2015-02-12 16:12:31,848 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-02-12 16:12:31,880 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop2-mr1
2015-02-12 16:12:31,880 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.operation.assertion.AppliedAssertionsPlatformTest
2015-02-12 16:12:31,900 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(105)) - not using cluster
2015-02-12 16:12:32,338 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-02-12 16:12:32,533 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:32,534 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:32,551 INFO property.AppProps (AppProps.java:getAppID(169)) - using app.id: 9976144D129A4D81BD5576AD9FC46493
2015-02-12 16:12:32,626 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:32,683 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:32,686 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:32,795 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 2.6.3
2015-02-12 16:12:32,797 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:32,797 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:32,798 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT"]
2015-02-12 16:12:32,798 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:32,799 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:32,799 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:32,801 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/value/NONE/STRICT
2015-02-12 16:12:32,820 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - session.id is deprecated. Instead, use dfs.metrics.session-id
2015-02-12 16:12:32,821 INFO jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=JobTracker, sessionId=
2015-02-12 16:12:32,839 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:33,028 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:33,058 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:33,203 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local1565370509_0001
2015-02-12 16:12:33,233 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1565370509/.staging/job_local1565370509_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:33,240 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1565370509/.staging/job_local1565370509_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:33,371 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1565370509_0001/job_local1565370509_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:33,376 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1565370509_0001/job_local1565370509_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:33,387 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:33,388 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:33,389 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:33,390 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1565370509_0001
2015-02-12 16:12:33,390 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:33,409 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:33,411 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1565370509_0001_m_000000_0
2015-02-12 16:12:33,440 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:33,441 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:33,446 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:33,447 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@6feab844
2015-02-12 16:12:33,455 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:33,498 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:33,498 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:33,498 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:33,498 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:33,499 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:33,514 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:33,519 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:33,519 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:33,556 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2015-02-12 16:12:33,566 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:33,567 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:33,579 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:33,580 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:33,580 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:33,580 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:33,580 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:33,586 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:33,589 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1565370509_0001_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:33,600 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:33,600 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1565370509_0001_m_000000_0' done.
2015-02-12 16:12:33,601 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1565370509_0001_m_000000_0
2015-02-12 16:12:33,601 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:33,604 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:33,604 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1565370509_0001_r_000000_0
2015-02-12 16:12:33,611 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:33,611 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:33,614 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@31174ed3
2015-02-12 16:12:33,625 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:33,628 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1565370509_0001_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:33,658 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#1 about to shuffle output of map attempt_local1565370509_0001_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:33,662 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1565370509_0001_m_000000_0
2015-02-12 16:12:33,690 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:33,690 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:33,691 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:33,692 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:33,697 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:33,697 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:33,700 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:33,700 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:33,701 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:33,702 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:33,703 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:33,704 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:33,706 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:33,706 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:33,721 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:33,721 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT"]
2015-02-12 16:12:33,752 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1565370509_0001_r_000000_0 is done. And is in the process of committing
2015-02-12 16:12:33,754 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:33,754 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local1565370509_0001_r_000000_0 is allowed to commit now
2015-02-12 16:12:33,757 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1565370509_0001_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT/_temporary/0/task_local1565370509_0001_r_000000
2015-02-12 16:12:33,758 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 16:12:33,758 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1565370509_0001_r_000000_0' done.
2015-02-12 16:12:33,758 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1565370509_0001_r_000000_0
2015-02-12 16:12:33,759 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:33,797 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT/_temporary
2015-02-12 16:12:33,844 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:33,869 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:33,870 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:33,885 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:33,888 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:33,890 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:33,905 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:33,905 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:33,905 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT"]
2015-02-12 16:12:33,905 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:33,905 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:33,905 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:33,906 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...atform/value/VALID/STRICT
2015-02-12 16:12:33,906 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:33,908 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:33,934 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:33,954 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:33,981 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local1536624252_0002
2015-02-12 16:12:33,998 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1536624252/.staging/job_local1536624252_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:33,999 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1536624252/.staging/job_local1536624252_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:34,052 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1536624252_0002/job_local1536624252_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:34,054 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1536624252_0002/job_local1536624252_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:34,054 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:34,054 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:34,054 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1536624252_0002
2015-02-12 16:12:34,055 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:34,055 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:34,057 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:34,058 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1536624252_0002_m_000000_0
2015-02-12 16:12:34,059 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:34,059 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:34,061 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:34,061 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@beaf1d1
2015-02-12 16:12:34,062 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:34,113 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:34,113 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:34,113 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:34,113 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:34,114 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:34,115 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:34,115 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:34,115 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:34,122 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:34,122 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:34,125 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:34,125 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:34,125 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:34,126 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:34,126 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:34,128 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:34,130 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1536624252_0002_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:34,131 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:34,131 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1536624252_0002_m_000000_0' done.
2015-02-12 16:12:34,131 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1536624252_0002_m_000000_0
2015-02-12 16:12:34,131 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:34,132 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:34,132 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1536624252_0002_r_000000_0
2015-02-12 16:12:34,133 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:34,133 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:34,134 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@745ae682
2015-02-12 16:12:34,134 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:34,135 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1536624252_0002_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:34,136 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#2 about to shuffle output of map attempt_local1536624252_0002_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:34,136 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1536624252_0002_m_000000_0
2015-02-12 16:12:34,137 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:34,137 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:34,138 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:34,138 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:34,140 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:34,140 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:34,142 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:34,142 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:34,142 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:34,142 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:34,143 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:34,143 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:34,144 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:34,144 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:34,153 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:34,153 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT"]
2015-02-12 16:12:34,166 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1536624252_0002_r_000000_0 is done. And is in the process of committing
2015-02-12 16:12:34,168 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:34,168 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local1536624252_0002_r_000000_0 is allowed to commit now
2015-02-12 16:12:34,169 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1536624252_0002_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT/_temporary/0/task_local1536624252_0002_r_000000
2015-02-12 16:12:34,170 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 16:12:34,170 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1536624252_0002_r_000000_0' done.
2015-02-12 16:12:34,170 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1536624252_0002_r_000000_0
2015-02-12 16:12:34,170 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:34,194 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT/_temporary
2015-02-12 16:12:34,230 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:34,252 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:34,253 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:34,264 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:34,269 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:34,270 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:34,285 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:34,285 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:34,286 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/STRICT/STRICT"]
2015-02-12 16:12:34,286 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:34,286 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:34,286 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:34,286 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...tform/value/STRICT/STRICT
2015-02-12 16:12:34,287 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:34,288 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:34,315 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:34,337 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:34,398 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local866988105_0003
2015-02-12 16:12:34,419 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi866988105/.staging/job_local866988105_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:34,421 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi866988105/.staging/job_local866988105_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:34,507 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local866988105_0003/job_local866988105_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:34,509 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local866988105_0003/job_local866988105_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:34,509 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:34,510 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:34,510 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:34,510 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local866988105_0003
2015-02-12 16:12:34,510 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:34,512 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:34,513 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local866988105_0003_m_000000_0
2015-02-12 16:12:34,514 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:34,514 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:34,516 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:34,516 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4263d89c
2015-02-12 16:12:34,518 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:34,569 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:34,569 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:34,569 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:34,569 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:34,570 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:34,570 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:34,571 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:34,571 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:34,579 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:34,579 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:34,582 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:34,583 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:34,583 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:34,583 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:34,583 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:34,585 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:34,587 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local866988105_0003_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:34,589 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:34,589 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local866988105_0003_m_000000_0' done.
2015-02-12 16:12:34,589 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local866988105_0003_m_000000_0
2015-02-12 16:12:34,589 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:34,590 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:34,590 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local866988105_0003_r_000000_0
2015-02-12 16:12:34,592 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:34,592 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:34,592 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@4c32cdeb
2015-02-12 16:12:34,593 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:34,593 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local866988105_0003_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:34,594 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#3 about to shuffle output of map attempt_local866988105_0003_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:34,595 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local866988105_0003_m_000000_0
2015-02-12 16:12:34,595 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:34,595 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:34,596 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:34,596 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:34,598 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:34,598 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:34,601 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:34,601 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:34,601 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:34,601 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:34,602 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:34,602 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:34,603 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:34,603 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:34,612 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:34,613 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/STRICT/STRICT"]
2015-02-12 16:12:34,624 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:34,626 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:34,627 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:34,630 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local866988105_0003
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:34,639 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local866988105_0003 state at FAILED
2015-02-12 16:12:34,639 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-12 16:12:34,640 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-12 16:12:34,640 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-12 16:12:34,645 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-12 16:12:34,646 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...tform/value/STRICT/STRICT
2015-02-12 16:12:34,646 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-12 16:12:34,646 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] shutting down job executor
2015-02-12 16:12:34,646 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] shutdown complete
2015-02-12 16:12:34,647 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/STRICT/STRICT/_temporary
2015-02-12 16:12:34,679 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:34,680 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:34,690 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:34,693 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:34,694 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:34,703 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:34,703 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:34,703 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID"]
2015-02-12 16:12:34,703 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:34,703 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:34,703 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:34,704 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...platform/value/NONE/VALID
2015-02-12 16:12:34,704 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:34,706 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:34,754 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:34,777 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:34,797 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local158402947_0004
2015-02-12 16:12:34,819 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi158402947/.staging/job_local158402947_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:34,820 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi158402947/.staging/job_local158402947_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:34,878 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local158402947_0004/job_local158402947_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:34,880 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local158402947_0004/job_local158402947_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:34,881 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:34,881 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:34,884 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:34,884 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local158402947_0004_m_000000_0
2015-02-12 16:12:34,886 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:34,886 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:34,887 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:34,888 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@6210d510
2015-02-12 16:12:34,889 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:34,892 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:34,897 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local158402947_0004
2015-02-12 16:12:34,897 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:34,904 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:34,904 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:34,904 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:34,904 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:34,904 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:34,905 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:34,905 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:34,906 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:34,913 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:34,913 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:34,918 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:34,918 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:34,918 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:34,918 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:34,918 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:34,921 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:34,924 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local158402947_0004_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:34,925 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:34,926 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local158402947_0004_m_000000_0' done.
2015-02-12 16:12:34,926 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local158402947_0004_m_000000_0
2015-02-12 16:12:34,926 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:34,927 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:34,927 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local158402947_0004_r_000000_0
2015-02-12 16:12:34,929 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:34,929 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:34,929 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@3744cc2c
2015-02-12 16:12:34,930 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:34,931 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local158402947_0004_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:34,933 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#4 about to shuffle output of map attempt_local158402947_0004_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:34,933 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local158402947_0004_m_000000_0
2015-02-12 16:12:34,933 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:34,935 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:34,936 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:34,936 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:34,938 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:34,938 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:34,940 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:34,940 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:34,940 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:34,940 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:34,940 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:34,941 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:34,941 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:34,941 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:34,951 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:34,952 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID"]
2015-02-12 16:12:34,964 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local158402947_0004_r_000000_0 is done. And is in the process of committing
2015-02-12 16:12:34,966 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:34,966 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local158402947_0004_r_000000_0 is allowed to commit now
2015-02-12 16:12:34,967 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local158402947_0004_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID/_temporary/0/task_local158402947_0004_r_000000
2015-02-12 16:12:34,968 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 16:12:34,969 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local158402947_0004_r_000000_0' done.
2015-02-12 16:12:34,969 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local158402947_0004_r_000000_0
2015-02-12 16:12:34,969 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:34,992 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID/_temporary
2015-02-12 16:12:35,030 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:35,056 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:35,056 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:35,066 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:35,069 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:35,069 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:35,077 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:35,077 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:35,077 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/VALID"]
2015-02-12 16:12:35,077 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:35,078 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:35,078 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:35,078 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/value/VALID/VALID
2015-02-12 16:12:35,079 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:35,079 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:35,101 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:35,119 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:35,134 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local1152949515_0005
2015-02-12 16:12:35,150 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1152949515/.staging/job_local1152949515_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:35,152 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi1152949515/.staging/job_local1152949515_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:35,193 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1152949515_0005/job_local1152949515_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:35,195 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local1152949515_0005/job_local1152949515_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:35,196 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:35,196 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1152949515_0005
2015-02-12 16:12:35,196 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:35,196 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:35,197 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:35,201 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:35,201 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1152949515_0005_m_000000_0
2015-02-12 16:12:35,203 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:35,203 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:35,204 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:35,205 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@502f719a
2015-02-12 16:12:35,205 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:35,232 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:35,232 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:35,232 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:35,233 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:35,233 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:35,234 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:35,234 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:35,234 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:35,242 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:35,242 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:35,245 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:35,245 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:35,246 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:35,246 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:35,246 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:35,249 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:35,252 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local1152949515_0005_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:35,253 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:35,254 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1152949515_0005_m_000000_0' done.
2015-02-12 16:12:35,254 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1152949515_0005_m_000000_0
2015-02-12 16:12:35,254 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:35,254 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:35,255 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1152949515_0005_r_000000_0
2015-02-12 16:12:35,256 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:35,257 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:35,257 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@7cf4e338
2015-02-12 16:12:35,257 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:35,258 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1152949515_0005_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:35,259 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#5 about to shuffle output of map attempt_local1152949515_0005_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:35,260 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1152949515_0005_m_000000_0
2015-02-12 16:12:35,260 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:35,261 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:35,262 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:35,262 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:35,264 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:35,264 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:35,265 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:35,265 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:35,266 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:35,266 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:35,266 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:35,267 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:35,267 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:35,267 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:35,274 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:35,275 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/VALID"]
2015-02-12 16:12:35,284 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:35,284 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:35,285 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:35,287 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local1152949515_0005
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:35,297 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local1152949515_0005 state at FAILED
2015-02-12 16:12:35,297 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-12 16:12:35,298 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-12 16:12:35,298 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-12 16:12:35,305 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-12 16:12:35,305 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...latform/value/VALID/VALID
2015-02-12 16:12:35,305 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-12 16:12:35,306 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/VALID/_temporary
2015-02-12 16:12:35,306 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/VALID/VALID
2015-02-12 16:12:35,306 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/STRICT/STRICT
2015-02-12 16:12:35,307 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT
2015-02-12 16:12:35,307 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID
2015-02-12 16:12:35,307 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT
2015-02-12 16:12:35,325 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:35,325 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:35,332 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:35,334 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:35,335 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:35,341 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:35,341 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:35,342 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT"]
2015-02-12 16:12:35,342 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:35,342 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:35,342 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:35,342 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/group/NONE/STRICT
2015-02-12 16:12:35,343 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:35,344 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:35,367 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:35,385 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:35,400 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local381398758_0006
2015-02-12 16:12:35,416 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi381398758/.staging/job_local381398758_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:35,417 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi381398758/.staging/job_local381398758_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:35,454 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local381398758_0006/job_local381398758_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:35,455 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local381398758_0006/job_local381398758_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:35,456 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:35,456 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local381398758_0006
2015-02-12 16:12:35,456 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:35,456 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:35,456 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:35,459 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:35,459 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local381398758_0006_m_000000_0
2015-02-12 16:12:35,460 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:35,461 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:35,462 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:35,462 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@710c93d7
2015-02-12 16:12:35,463 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:35,488 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:35,489 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:35,490 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:35,490 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:35,490 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:35,491 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:35,491 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:35,491 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:35,497 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:35,497 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:35,500 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:35,500 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:35,501 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:35,501 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:35,501 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:35,504 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:35,506 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local381398758_0006_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:35,509 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:35,509 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local381398758_0006_m_000000_0' done.
2015-02-12 16:12:35,509 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local381398758_0006_m_000000_0
2015-02-12 16:12:35,509 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:35,510 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:35,510 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local381398758_0006_r_000000_0
2015-02-12 16:12:35,512 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:35,512 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:35,512 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@2dfdd4ce
2015-02-12 16:12:35,513 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:35,513 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local381398758_0006_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:35,515 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#6 about to shuffle output of map attempt_local381398758_0006_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:35,515 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local381398758_0006_m_000000_0
2015-02-12 16:12:35,515 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:35,516 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:35,517 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:35,517 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:35,519 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:35,519 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:35,520 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:35,521 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:35,521 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:35,521 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:35,521 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:35,522 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:35,523 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:35,523 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:35,529 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:35,530 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT"]
2015-02-12 16:12:35,540 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local381398758_0006_r_000000_0 is done. And is in the process of committing
2015-02-12 16:12:35,541 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:35,541 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local381398758_0006_r_000000_0 is allowed to commit now
2015-02-12 16:12:35,542 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local381398758_0006_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT/_temporary/0/task_local381398758_0006_r_000000
2015-02-12 16:12:35,543 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 16:12:35,543 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local381398758_0006_r_000000_0' done.
2015-02-12 16:12:35,544 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local381398758_0006_r_000000_0
2015-02-12 16:12:35,544 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:35,558 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT/_temporary
2015-02-12 16:12:35,582 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:35,596 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:35,597 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:35,605 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:35,607 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:35,608 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:35,617 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:35,617 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:35,617 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT"]
2015-02-12 16:12:35,617 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:35,617 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:35,617 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:35,618 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...atform/group/VALID/STRICT
2015-02-12 16:12:35,618 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:35,620 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:35,648 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:35,667 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:35,683 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local772157388_0007
2015-02-12 16:12:35,695 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi772157388/.staging/job_local772157388_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:35,695 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi772157388/.staging/job_local772157388_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:35,733 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local772157388_0007/job_local772157388_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:35,734 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local772157388_0007/job_local772157388_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:35,735 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:35,735 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:35,735 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:35,735 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local772157388_0007
2015-02-12 16:12:35,735 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:35,739 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:35,739 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local772157388_0007_m_000000_0
2015-02-12 16:12:35,740 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:35,740 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:35,741 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:35,741 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@13389ea8
2015-02-12 16:12:35,742 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:35,765 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:35,767 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:35,767 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:35,767 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:35,767 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:35,768 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:35,768 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:35,768 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:35,773 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:35,773 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:35,776 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:35,776 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:35,777 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:35,777 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:35,778 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:35,781 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:35,783 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local772157388_0007_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:35,785 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:35,785 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local772157388_0007_m_000000_0' done.
2015-02-12 16:12:35,785 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local772157388_0007_m_000000_0
2015-02-12 16:12:35,785 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:35,787 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:35,787 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local772157388_0007_r_000000_0
2015-02-12 16:12:35,789 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:35,789 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:35,789 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@507ca72d
2015-02-12 16:12:35,790 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:35,790 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local772157388_0007_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:35,792 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#7 about to shuffle output of map attempt_local772157388_0007_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:35,792 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local772157388_0007_m_000000_0
2015-02-12 16:12:35,792 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:35,793 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:35,794 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:35,794 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:35,796 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:35,796 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:35,797 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:35,798 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:35,798 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:35,798 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:35,798 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:35,799 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:35,799 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:35,799 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:35,805 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:35,805 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT"]
2015-02-12 16:12:35,816 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local772157388_0007_r_000000_0 is done. And is in the process of committing
2015-02-12 16:12:35,817 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:35,817 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local772157388_0007_r_000000_0 is allowed to commit now
2015-02-12 16:12:35,818 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local772157388_0007_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT/_temporary/0/task_local772157388_0007_r_000000
2015-02-12 16:12:35,819 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 16:12:35,819 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local772157388_0007_r_000000_0' done.
2015-02-12 16:12:35,819 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local772157388_0007_r_000000_0
2015-02-12 16:12:35,819 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:35,847 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT/_temporary
2015-02-12 16:12:35,869 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:35,883 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:35,883 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:35,893 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:35,895 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:35,895 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:35,905 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:35,905 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:35,906 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/STRICT/STRICT"]
2015-02-12 16:12:35,906 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:35,906 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:35,906 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:35,906 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...tform/group/STRICT/STRICT
2015-02-12 16:12:35,907 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:35,908 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:35,932 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:35,954 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:35,967 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local641362972_0008
2015-02-12 16:12:35,979 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi641362972/.staging/job_local641362972_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:35,979 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi641362972/.staging/job_local641362972_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:36,025 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local641362972_0008/job_local641362972_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:36,026 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local641362972_0008/job_local641362972_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:36,026 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:36,026 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local641362972_0008
2015-02-12 16:12:36,026 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:36,026 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:36,027 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:36,029 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:36,029 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local641362972_0008_m_000000_0
2015-02-12 16:12:36,030 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:36,031 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:36,032 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:36,032 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@14a38d02
2015-02-12 16:12:36,033 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:36,051 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:36,052 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:36,052 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:36,052 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:36,052 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:36,053 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:36,053 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:36,054 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:36,059 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:36,059 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:36,062 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:36,063 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:36,063 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:36,063 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:36,063 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:36,065 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:36,067 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local641362972_0008_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:36,068 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:36,069 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local641362972_0008_m_000000_0' done.
2015-02-12 16:12:36,069 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local641362972_0008_m_000000_0
2015-02-12 16:12:36,069 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:36,069 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:36,070 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local641362972_0008_r_000000_0
2015-02-12 16:12:36,071 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:36,071 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:36,071 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@1cd1cf9c
2015-02-12 16:12:36,072 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:36,073 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local641362972_0008_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:36,074 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#8 about to shuffle output of map attempt_local641362972_0008_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:36,074 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local641362972_0008_m_000000_0
2015-02-12 16:12:36,074 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:36,075 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:36,075 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:36,076 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:36,077 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:36,077 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:36,078 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:36,079 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:36,079 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:36,079 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:36,079 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:36,080 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:36,080 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:36,080 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:36,085 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:36,085 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/STRICT/STRICT"]
2015-02-12 16:12:36,093 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:36,093 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:36,094 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:36,096 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local641362972_0008
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:36,098 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local641362972_0008 state at FAILED
2015-02-12 16:12:36,099 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-12 16:12:36,099 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-12 16:12:36,099 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-12 16:12:36,102 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-12 16:12:36,102 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...tform/group/STRICT/STRICT
2015-02-12 16:12:36,103 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-12 16:12:36,103 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/STRICT/STRICT/_temporary
2015-02-12 16:12:36,117 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:36,117 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:36,124 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:36,126 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:36,127 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:36,135 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:36,135 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:36,135 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID"]
2015-02-12 16:12:36,136 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:36,136 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:36,136 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:36,137 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...platform/group/NONE/VALID
2015-02-12 16:12:36,138 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:36,139 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:36,164 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:36,182 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:36,197 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local207216902_0009
2015-02-12 16:12:36,212 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi207216902/.staging/job_local207216902_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:36,213 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi207216902/.staging/job_local207216902_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:36,250 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local207216902_0009/job_local207216902_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:36,251 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local207216902_0009/job_local207216902_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:36,251 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:36,251 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:36,252 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:36,251 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local207216902_0009
2015-02-12 16:12:36,252 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:36,254 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:36,254 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local207216902_0009_m_000000_0
2015-02-12 16:12:36,255 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:36,255 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:36,256 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:36,256 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@a82d235
2015-02-12 16:12:36,257 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:36,277 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:36,277 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:36,278 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:36,278 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:36,278 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:36,278 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:36,279 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:36,279 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:36,283 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:36,283 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:36,285 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:36,285 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:36,286 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:36,286 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:36,286 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:36,287 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:36,289 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local207216902_0009_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:36,290 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:36,290 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local207216902_0009_m_000000_0' done.
2015-02-12 16:12:36,290 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local207216902_0009_m_000000_0
2015-02-12 16:12:36,290 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:36,291 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:36,291 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local207216902_0009_r_000000_0
2015-02-12 16:12:36,292 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:36,292 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:36,292 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@465670b4
2015-02-12 16:12:36,293 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:36,293 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local207216902_0009_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:36,294 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#9 about to shuffle output of map attempt_local207216902_0009_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:36,295 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local207216902_0009_m_000000_0
2015-02-12 16:12:36,295 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:36,295 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:36,296 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:36,296 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:36,297 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:36,297 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:36,299 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:36,299 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:36,299 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:36,299 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:36,300 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:36,300 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:36,300 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:36,301 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:36,305 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:36,305 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID"]
2015-02-12 16:12:36,314 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local207216902_0009_r_000000_0 is done. And is in the process of committing
2015-02-12 16:12:36,315 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:36,315 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local207216902_0009_r_000000_0 is allowed to commit now
2015-02-12 16:12:36,316 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local207216902_0009_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID/_temporary/0/task_local207216902_0009_r_000000
2015-02-12 16:12:36,317 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 16:12:36,317 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local207216902_0009_r_000000_0' done.
2015-02-12 16:12:36,317 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local207216902_0009_r_000000_0
2015-02-12 16:12:36,317 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:36,341 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID/_temporary
2015-02-12 16:12:36,366 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:36,384 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:36,385 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:36,391 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:36,393 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:36,394 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:36,402 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:36,402 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:36,403 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/VALID"]
2015-02-12 16:12:36,403 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:36,403 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:36,403 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:36,404 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/group/VALID/VALID
2015-02-12 16:12:36,404 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:36,405 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:36,436 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:36,462 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:36,487 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local90412366_0010
2015-02-12 16:12:36,507 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi90412366/.staging/job_local90412366_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:36,508 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi90412366/.staging/job_local90412366_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:36,559 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local90412366_0010/job_local90412366_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:36,561 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local90412366_0010/job_local90412366_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:36,562 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:36,562 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:36,562 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:36,562 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local90412366_0010
2015-02-12 16:12:36,563 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:36,565 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:36,565 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local90412366_0010_m_000000_0
2015-02-12 16:12:36,567 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:36,567 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:36,568 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:36,568 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@2029a303
2015-02-12 16:12:36,569 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:36,587 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:36,588 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:36,588 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:36,588 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:36,588 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:36,590 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:36,590 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:36,590 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:36,597 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:36,597 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:36,600 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:36,601 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:36,601 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:36,601 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:36,601 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:36,604 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:36,606 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local90412366_0010_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:36,608 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:36,608 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local90412366_0010_m_000000_0' done.
2015-02-12 16:12:36,609 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local90412366_0010_m_000000_0
2015-02-12 16:12:36,609 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:36,609 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:36,609 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local90412366_0010_r_000000_0
2015-02-12 16:12:36,611 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:36,612 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:36,612 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@dc1d5cd
2015-02-12 16:12:36,612 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:36,613 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local90412366_0010_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:36,614 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#10 about to shuffle output of map attempt_local90412366_0010_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:36,615 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local90412366_0010_m_000000_0
2015-02-12 16:12:36,615 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:36,615 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:36,616 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:36,616 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:36,618 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:36,618 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:36,620 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:36,620 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:36,620 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:36,620 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:36,621 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:36,621 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:36,621 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:36,621 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:36,628 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:36,628 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/VALID"]
2015-02-12 16:12:36,640 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:36,641 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:36,644 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:36,646 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local90412366_0010
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:36,653 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local90412366_0010 state at FAILED
2015-02-12 16:12:36,653 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-12 16:12:36,653 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-12 16:12:36,654 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-12 16:12:36,658 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-12 16:12:36,659 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...latform/group/VALID/VALID
2015-02-12 16:12:36,659 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-12 16:12:36,659 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/VALID/_temporary
2015-02-12 16:12:36,660 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT
2015-02-12 16:12:36,660 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT
2015-02-12 16:12:36,660 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/STRICT/STRICT
2015-02-12 16:12:36,660 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/VALID/VALID
2015-02-12 16:12:36,661 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID
2015-02-12 16:12:36,682 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:36,683 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:36,691 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:36,693 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:36,694 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:36,700 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:36,700 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:36,700 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/fail"]
2015-02-12 16:12:36,700 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:36,700 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:36,700 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:36,701 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...edassertionsplatform/fail
2015-02-12 16:12:36,701 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:36,703 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:36,731 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:36,756 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:36,774 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local420949778_0011
2015-02-12 16:12:36,794 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi420949778/.staging/job_local420949778_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:36,795 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi420949778/.staging/job_local420949778_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:36,840 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local420949778_0011/job_local420949778_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:36,841 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local420949778_0011/job_local420949778_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:36,842 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:36,842 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:36,842 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:36,842 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local420949778_0011
2015-02-12 16:12:36,842 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:36,844 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:36,844 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local420949778_0011_m_000000_0
2015-02-12 16:12:36,846 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:36,846 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:36,847 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:36,847 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@102bdf72
2015-02-12 16:12:36,848 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:36,867 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:36,867 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:36,867 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:36,867 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:36,867 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:36,868 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:36,868 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:36,869 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:36,876 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:36,876 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:36,880 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:36,880 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:36,880 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:36,880 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:36,880 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:36,883 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:36,884 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local420949778_0011_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:36,886 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:36,886 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local420949778_0011_m_000000_0' done.
2015-02-12 16:12:36,886 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local420949778_0011_m_000000_0
2015-02-12 16:12:36,887 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:36,887 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:36,887 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local420949778_0011_r_000000_0
2015-02-12 16:12:36,889 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:36,889 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:36,889 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@5cab14f4
2015-02-12 16:12:36,890 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:36,891 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local420949778_0011_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:36,892 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#11 about to shuffle output of map attempt_local420949778_0011_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:36,893 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local420949778_0011_m_000000_0
2015-02-12 16:12:36,893 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:36,893 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:36,894 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:36,894 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:36,896 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:36,896 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:36,898 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:36,898 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:36,898 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:36,898 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:36,899 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:36,899 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:36,900 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:36,900 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:36,906 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:36,907 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/fail"]
2015-02-12 16:12:36,917 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testGroupAssertionsFail(AppliedAssertionsPlatformTest.java:236)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:36,917 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testGroupAssertionsFail(AppliedAssertionsPlatformTest.java:236)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:36,918 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:36,920 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local420949778_0011
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testGroupAssertionsFail(AppliedAssertionsPlatformTest.java:236)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testGroupAssertionsFail(AppliedAssertionsPlatformTest.java:236)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:36,923 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local420949778_0011 state at FAILED
2015-02-12 16:12:36,923 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-12 16:12:36,923 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-12 16:12:36,923 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-12 16:12:36,928 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-12 16:12:36,928 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...edassertionsplatform/fail
2015-02-12 16:12:36,929 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-12 16:12:36,929 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/fail/_temporary
2015-02-12 16:12:36,930 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/fail
2015-02-12 16:12:36,952 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:36,952 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:36,961 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:36,963 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:36,963 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:36,969 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:36,970 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:36,970 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/pass"]
2015-02-12 16:12:36,970 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:36,971 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:36,971 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:36,971 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...edassertionsplatform/pass
2015-02-12 16:12:36,972 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:36,973 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:37,003 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:37,028 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:37,044 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local244454931_0012
2015-02-12 16:12:37,064 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi244454931/.staging/job_local244454931_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:37,065 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi244454931/.staging/job_local244454931_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:37,113 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local244454931_0012/job_local244454931_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:37,114 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local244454931_0012/job_local244454931_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:37,115 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:37,115 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local244454931_0012
2015-02-12 16:12:37,115 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:37,115 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:37,115 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:37,117 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:37,117 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local244454931_0012_m_000000_0
2015-02-12 16:12:37,118 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:37,118 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:37,120 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:37,120 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@a24b738
2015-02-12 16:12:37,121 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:37,136 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:37,137 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:37,137 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:37,137 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:37,137 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:37,138 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:37,138 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:37,139 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:37,146 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:37,146 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:37,149 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:37,150 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:37,150 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:37,150 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:37,150 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:37,152 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:37,154 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local244454931_0012_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:37,155 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:37,156 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local244454931_0012_m_000000_0' done.
2015-02-12 16:12:37,156 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local244454931_0012_m_000000_0
2015-02-12 16:12:37,156 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:37,156 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:37,156 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local244454931_0012_r_000000_0
2015-02-12 16:12:37,158 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:37,158 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:37,158 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@342fbb28
2015-02-12 16:12:37,158 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:37,159 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local244454931_0012_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:37,160 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#12 about to shuffle output of map attempt_local244454931_0012_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:37,161 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local244454931_0012_m_000000_0
2015-02-12 16:12:37,161 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:37,161 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:37,162 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:37,163 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:37,165 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:37,165 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:37,166 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:37,167 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:37,167 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:37,167 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:37,167 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:37,168 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:37,168 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:37,168 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:37,174 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:37,174 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/pass"]
2015-02-12 16:12:37,185 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local244454931_0012_r_000000_0 is done. And is in the process of committing
2015-02-12 16:12:37,186 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:37,187 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local244454931_0012_r_000000_0 is allowed to commit now
2015-02-12 16:12:37,187 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local244454931_0012_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/pass/_temporary/0/task_local244454931_0012_r_000000
2015-02-12 16:12:37,189 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 16:12:37,189 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local244454931_0012_r_000000_0' done.
2015-02-12 16:12:37,189 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local244454931_0012_r_000000_0
2015-02-12 16:12:37,189 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:37,206 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/pass/_temporary
2015-02-12 16:12:37,231 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:37,232 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/pass
2015-02-12 16:12:37,244 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:37,244 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:37,250 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:37,251 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:37,252 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:37,256 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:37,257 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:37,257 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/fail"]
2015-02-12 16:12:37,257 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:37,257 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:37,257 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:37,258 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...rtionsplatform/value/fail
2015-02-12 16:12:37,258 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:37,259 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:37,280 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:37,297 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:37,309 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local764611234_0013
2015-02-12 16:12:37,322 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi764611234/.staging/job_local764611234_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:37,323 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi764611234/.staging/job_local764611234_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:37,360 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local764611234_0013/job_local764611234_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:37,361 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local764611234_0013/job_local764611234_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:37,361 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:37,362 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local764611234_0013
2015-02-12 16:12:37,362 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:37,362 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:37,362 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:37,363 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:37,364 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local764611234_0013_m_000000_0
2015-02-12 16:12:37,365 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:37,365 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:37,365 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:37,366 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@7c994b98
2015-02-12 16:12:37,367 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:37,386 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:37,386 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:37,386 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:37,387 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:37,387 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:37,388 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:37,388 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:37,388 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:37,392 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:37,393 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:37,395 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:37,395 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:37,395 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:37,395 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:37,395 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:37,397 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:37,398 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local764611234_0013_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:37,400 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:37,400 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local764611234_0013_m_000000_0' done.
2015-02-12 16:12:37,400 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local764611234_0013_m_000000_0
2015-02-12 16:12:37,400 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:37,401 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:37,401 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local764611234_0013_r_000000_0
2015-02-12 16:12:37,402 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:37,402 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:37,403 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@30263191
2015-02-12 16:12:37,404 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:37,405 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local764611234_0013_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:37,405 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#13 about to shuffle output of map attempt_local764611234_0013_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:37,406 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local764611234_0013_m_000000_0
2015-02-12 16:12:37,406 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:37,406 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:37,407 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:37,407 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:37,408 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:37,408 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:37,409 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:37,410 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:37,410 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:37,410 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:37,410 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:37,411 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:37,411 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:37,411 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:37,415 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:37,415 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/fail"]
2015-02-12 16:12:37,423 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testValueAssertionsFail(AppliedAssertionsPlatformTest.java:111)] argument tuple: ['7'] was not equal to values: ['0']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:37,424 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testValueAssertionsFail(AppliedAssertionsPlatformTest.java:111)] argument tuple: ['7'] was not equal to values: ['0']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:37,426 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:37,428 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local764611234_0013
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testValueAssertionsFail(AppliedAssertionsPlatformTest.java:111)] argument tuple: ['7'] was not equal to values: ['0']
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testValueAssertionsFail(AppliedAssertionsPlatformTest.java:111)] argument tuple: ['7'] was not equal to values: ['0']
at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-12 16:12:37,433 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local764611234_0013 state at FAILED
2015-02-12 16:12:37,433 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-12 16:12:37,433 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-12 16:12:37,433 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-12 16:12:37,441 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-12 16:12:37,441 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...rtionsplatform/value/fail
2015-02-12 16:12:37,441 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-12 16:12:37,442 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/fail/_temporary
2015-02-12 16:12:37,442 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/fail
2015-02-12 16:12:37,456 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-12 16:12:37,457 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /Users/soberoi/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-12 16:12:37,462 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-12 16:12:37,463 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-12 16:12:37,464 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1022)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-12 16:12:37,469 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-12 16:12:37,469 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:37,470 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/pass"]
2015-02-12 16:12:37,470 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-12 16:12:37,470 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-12 16:12:37,470 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-12 16:12:37,470 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...rtionsplatform/value/pass
2015-02-12 16:12:37,471 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:37,472 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-12 16:12:37,492 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:37,510 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(492)) - number of splits:1
2015-02-12 16:12:37,522 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(575)) - Submitting tokens for job: job_local142922400_0014
2015-02-12 16:12:37,537 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi142922400/.staging/job_local142922400_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:37,538 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/tmp/cascading/staging/soberoi142922400/.staging/job_local142922400_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:37,576 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local142922400_0014/job_local142922400_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-12 16:12:37,577 WARN conf.Configuration (Configuration.java:loadProperty(2510)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/tmp/mapred/local/localRunner/soberoi/job_local142922400_0014/job_local142922400_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-12 16:12:37,578 INFO mapreduce.Job (Job.java:submit(1299)) - The url to track the job: http://localhost:8080/
2015-02-12 16:12:37,579 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-12 16:12:37,579 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-12 16:12:37,582 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-12 16:12:37,583 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local142922400_0014_m_000000_0
2015-02-12 16:12:37,584 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:37,584 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:37,585 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt
2015-02-12 16:12:37,585 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(482)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@349e15b
2015-02-12 16:12:37,586 INFO mapred.MapTask (MapTask.java:runOldMapper(436)) - numReduceTasks: 1
2015-02-12 16:12:37,600 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local142922400_0014
2015-02-12 16:12:37,600 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-12 16:12:37,604 INFO mapred.MapTask (MapTask.java:setEquator(1202)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-12 16:12:37,604 INFO mapred.MapTask (MapTask.java:init(995)) - mapreduce.task.io.sort.mb: 100
2015-02-12 16:12:37,604 INFO mapred.MapTask (MapTask.java:init(996)) - soft limit at 83886080
2015-02-12 16:12:37,604 INFO mapred.MapTask (MapTask.java:init(997)) - bufstart = 0; bufvoid = 104857600
2015-02-12 16:12:37,604 INFO mapred.MapTask (MapTask.java:init(998)) - kvstart = 26214396; length = 6553600
2015-02-12 16:12:37,605 INFO mapred.MapTask (MapTask.java:createSortingCollector(402)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-12 16:12:37,606 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-12 16:12:37,606 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-12 16:12:37,611 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt"]
2015-02-12 16:12:37,612 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:37,614 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-12 16:12:37,614 INFO mapred.MapTask (MapTask.java:flush(1457)) - Starting flush of map output
2015-02-12 16:12:37,614 INFO mapred.MapTask (MapTask.java:flush(1475)) - Spilling map output
2015-02-12 16:12:37,614 INFO mapred.MapTask (MapTask.java:flush(1476)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-12 16:12:37,614 INFO mapred.MapTask (MapTask.java:flush(1478)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-12 16:12:37,616 INFO mapred.MapTask (MapTask.java:sortAndSpill(1660)) - Finished spill 0
2015-02-12 16:12:37,617 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local142922400_0014_m_000000_0 is done. And is in the process of committing
2015-02-12 16:12:37,618 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/classes/test/data/apache.10.txt:0+1449
2015-02-12 16:12:37,618 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local142922400_0014_m_000000_0' done.
2015-02-12 16:12:37,619 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local142922400_0014_m_000000_0
2015-02-12 16:12:37,619 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-12 16:12:37,619 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-12 16:12:37,619 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local142922400_0014_r_000000_0
2015-02-12 16:12:37,620 INFO util.ProcfsBasedProcessTree (ProcfsBasedProcessTree.java:isAvailable(181)) - ProcfsBasedProcessTree currently is supported only on Linux.
2015-02-12 16:12:37,620 INFO mapred.Task (Task.java:initialize(587)) - Using ResourceCalculatorProcessTree : null
2015-02-12 16:12:37,620 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@42c08a7e
2015-02-12 16:12:37,621 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(195)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-12 16:12:37,622 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local142922400_0014_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-12 16:12:37,622 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(141)) - localfetcher#14 about to shuffle output of map attempt_local142922400_0014_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-12 16:12:37,623 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local142922400_0014_m_000000_0
2015-02-12 16:12:37,623 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(313)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-12 16:12:37,623 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-12 16:12:37,624 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:37,624 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(673)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-12 16:12:37,625 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:37,625 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:37,626 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(750)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-12 16:12:37,627 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(780)) - Merging 1 files, 713 bytes from disk
2015-02-12 16:12:37,627 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(795)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-12 16:12:37,627 INFO mapred.Merger (Merger.java:merge(606)) - Merging 1 sorted segments
2015-02-12 16:12:37,627 INFO mapred.Merger (Merger.java:merge(705)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-12 16:12:37,628 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:37,628 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-12 16:12:37,628 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-12 16:12:37,632 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-12 16:12:37,632 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/pass"]
2015-02-12 16:12:37,641 INFO mapred.Task (Task.java:done(1001)) - Task:attempt_local142922400_0014_r_000000_0 is done. And is in the process of committing
2015-02-12 16:12:37,642 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-12 16:12:37,642 INFO mapred.Task (Task.java:commit(1162)) - Task attempt_local142922400_0014_r_000000_0 is allowed to commit now
2015-02-12 16:12:37,642 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local142922400_0014_r_000000_0' to file:/Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/pass/_temporary/0/task_local142922400_0014_r_000000
2015-02-12 16:12:37,643 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-12 16:12:37,643 INFO mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local142922400_0014_r_000000_0' done.
2015-02-12 16:12:37,643 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local142922400_0014_r_000000_0
2015-02-12 16:12:37,643 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-12 16:12:37,663 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/pass/_temporary
2015-02-12 16:12:37,687 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-12 16:12:37,689 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /Users/soberoi/src/compatibility/cascading.compatibility/cloudera/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/pass