Class cascading.cascade.RiffleCascadePlatformTest

7

tests

0

failures

0

ignored

4.626s

duration

100%

successful

Tests

Test Duration Result
testProcessFlowFlowListenerExceptionHandlingInComplete 0.005s passed
testProcessFlowFlowListenerExceptionHandlingInStart 0.004s passed
testProcessFlowFlowListenerExceptionHandlingInStop 0.011s passed
testProcessFlowWithChildCounters 0.891s passed
testProcessFlowWithCounters 0.006s passed
testSimpleRiffle 2.664s passed
testSimpleRiffleCascade 1.045s passed

Standard output

2016-01-14 21:11:39,397 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 21:11:39,421 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.cascade.RiffleCascadePlatformTest, with platform: hadoop2-mr1
2016-01-14 21:11:39,455 INFO  hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-01-14 21:11:40,068 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-01-14 21:11:40,245 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides: 
2016-01-14 21:11:40,300 INFO  property.AppProps (AppProps.java:getAppID(177)) - using app.id: C90B2852B4CA49BBADC5E089D957A4B3
2016-01-14 21:11:40,342 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowWithChildCounters/children/first
2016-01-14 21:11:40,355 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInStop/stopException/first
2016-01-14 21:11:40,444 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:11:40,446 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:11:40,688 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.087
2016-01-14 21:11:40,691 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:11:40,691 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:11:40,834 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:11:40,835 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:11:40,907 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.058
2016-01-14 21:11:40,911 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:11:40,911 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:11:40,955 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:11:40,956 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:11:41,007 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.041
2016-01-14 21:11:41,008 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:11:41,009 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:11:41,049 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:11:41,050 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:11:41,106 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.049
2016-01-14 21:11:41,108 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:11:41,109 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:11:41,203 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 21:11:41,204 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 21:11:41,205 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:11:41,205 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-01-14 21:11:41,205 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  parallel execution of steps is enabled: false
2016-01-14 21:11:41,205 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  executing total steps: 1
2016-01-14 21:11:41,206 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  allocating management threads: 1
2016-01-14 21:11:41,225 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...pleRiffle/perpetual/first
2016-01-14 21:11:41,771 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity107557446/.staging/job_local107557446_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:41,777 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity107557446/.staging/job_local107557446_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:41,961 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local107557446_0001/job_local107557446_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:41,965 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local107557446_0001/job_local107557446_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:41,972 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted hadoop job: job_local107557446_0001
2016-01-14 21:11:41,972 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tracking url: http://localhost:8080/
2016-01-14 21:11:42,076 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt
2016-01-14 21:11:42,102 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:11:42,102 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:11:42,114 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AA671236E6874BBCABCFEF38169E81E5, ordinal: 0
2016-01-14 21:11:42,152 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:11:42,153 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-01-14 21:11:42,153 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA671236E6874BBCABCFEF38169E81E5, mem on start (mb), free: 167, total: 223, max: 672
2016-01-14 21:11:42,167 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA671236E6874BBCABCFEF38169E81E5, mem on close (mb), free: 166, total: 223, max: 672
2016-01-14 21:11:42,218 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first/_temporary
2016-01-14 21:11:42,218 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  completed in: 00:01.012
2016-01-14 21:11:42,221 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting
2016-01-14 21:11:42,222 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-01-14 21:11:42,222 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-01-14 21:11:42,222 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  parallel execution of steps is enabled: false
2016-01-14 21:11:42,222 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  executing total steps: 1
2016-01-14 21:11:42,223 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  allocating management threads: 1
2016-01-14 21:11:42,223 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting step: (1/1) ...leRiffle/perpetual/second
2016-01-14 21:11:42,328 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity608385130/.staging/job_local608385130_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:42,329 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity608385130/.staging/job_local608385130_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:42,379 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local608385130_0002/job_local608385130_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:42,381 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local608385130_0002/job_local608385130_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:42,382 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] submitted hadoop job: job_local608385130_0002
2016-01-14 21:11:42,382 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] tracking url: http://localhost:8080/
2016-01-14 21:11:42,387 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first/part-00000
2016-01-14 21:11:42,396 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:11:42,397 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:11:42,406 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AE64BEF850734CC6AED16B50CDA80535, ordinal: 0
2016-01-14 21:11:42,407 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-01-14 21:11:42,408 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-01-14 21:11:42,408 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AE64BEF850734CC6AED16B50CDA80535, mem on start (mb), free: 192, total: 223, max: 672
2016-01-14 21:11:42,414 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AE64BEF850734CC6AED16B50CDA80535, mem on close (mb), free: 192, total: 223, max: 672
2016-01-14 21:11:42,437 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second/_temporary
2016-01-14 21:11:42,438 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  completed in: 00:00.216
2016-01-14 21:11:42,440 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting
2016-01-14 21:11:42,441 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-01-14 21:11:42,441 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-01-14 21:11:42,441 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  parallel execution of steps is enabled: false
2016-01-14 21:11:42,441 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  executing total steps: 1
2016-01-14 21:11:42,441 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  allocating management threads: 1
2016-01-14 21:11:42,442 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting step: (1/1) ...pleRiffle/perpetual/third
2016-01-14 21:11:42,566 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity897125440/.staging/job_local897125440_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:42,569 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity897125440/.staging/job_local897125440_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:42,640 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local897125440_0003/job_local897125440_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:42,642 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local897125440_0003/job_local897125440_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:42,643 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] submitted hadoop job: job_local897125440_0003
2016-01-14 21:11:42,643 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] tracking url: http://localhost:8080/
2016-01-14 21:11:42,652 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second/part-00000
2016-01-14 21:11:42,665 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:11:42,665 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:11:42,679 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D6A58A0A1C354F6287C9FBDE0E69E8A1, ordinal: 0
2016-01-14 21:11:42,680 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-01-14 21:11:42,680 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-01-14 21:11:42,680 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6A58A0A1C354F6287C9FBDE0E69E8A1, mem on start (mb), free: 162, total: 223, max: 672
2016-01-14 21:11:42,684 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6A58A0A1C354F6287C9FBDE0E69E8A1, mem on close (mb), free: 162, total: 223, max: 672
2016-01-14 21:11:42,712 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third/_temporary
2016-01-14 21:11:42,713 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  completed in: 00:00.272
2016-01-14 21:11:42,717 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting
2016-01-14 21:11:42,717 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-01-14 21:11:42,717 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth"]
2016-01-14 21:11:42,717 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  parallel execution of steps is enabled: false
2016-01-14 21:11:42,717 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  executing total steps: 1
2016-01-14 21:11:42,719 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  allocating management threads: 1
2016-01-14 21:11:42,719 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting step: (1/1) ...leRiffle/perpetual/fourth
2016-01-14 21:11:42,852 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity843238770/.staging/job_local843238770_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:42,854 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity843238770/.staging/job_local843238770_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:42,909 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local843238770_0004/job_local843238770_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:42,910 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local843238770_0004/job_local843238770_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:42,910 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] submitted hadoop job: job_local843238770_0004
2016-01-14 21:11:42,911 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] tracking url: http://localhost:8080/
2016-01-14 21:11:42,918 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third/part-00000
2016-01-14 21:11:42,928 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:11:42,928 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:11:42,938 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B00394A12F2944F3BF6184B5B3345391, ordinal: 0
2016-01-14 21:11:42,938 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-01-14 21:11:42,938 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth"]
2016-01-14 21:11:42,939 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B00394A12F2944F3BF6184B5B3345391, mem on start (mb), free: 250, total: 281, max: 672
2016-01-14 21:11:42,942 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B00394A12F2944F3BF6184B5B3345391, mem on close (mb), free: 249, total: 281, max: 672
2016-01-14 21:11:42,973 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth/_temporary
2016-01-14 21:11:42,973 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  completed in: 00:00.256
2016-01-14 21:11:43,021 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth
2016-01-14 21:11:43,021 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first
2016-01-14 21:11:43,021 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third
2016-01-14 21:11:43,021 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second
2016-01-14 21:11:43,041 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:11:43,042 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:11:43,094 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.044
2016-01-14 21:11:43,096 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:11:43,096 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:11:43,121 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:11:43,121 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:11:43,154 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-01-14 21:11:43,155 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:11:43,155 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:11:43,179 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:11:43,180 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:11:43,212 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-01-14 21:11:43,213 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:11:43,213 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:11:43,235 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:11:43,236 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:11:43,264 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 21:11:43,265 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:11:43,265 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:11:43,293 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting
2016-01-14 21:11:43,294 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third]  parallel execution of flows is enabled: false
2016-01-14 21:11:43,294 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third]  executing total flows: 4
2016-01-14 21:11:43,294 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third]  allocating management threads: 1
2016-01-14 21:11:43,295 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: first
2016-01-14 21:11:43,295 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] at least one sink is marked for delete
2016-01-14 21:11:43,298 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:11:43,302 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 21:11:43,302 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:11:43,303 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-01-14 21:11:43,303 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  parallel execution of steps is enabled: false
2016-01-14 21:11:43,305 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  executing total steps: 1
2016-01-14 21:11:43,305 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  allocating management threads: 1
2016-01-14 21:11:43,306 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...de/perpetualcascade/first
2016-01-14 21:11:43,381 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1139006066/.staging/job_local1139006066_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:43,382 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1139006066/.staging/job_local1139006066_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:43,431 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1139006066_0005/job_local1139006066_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:43,432 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1139006066_0005/job_local1139006066_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:43,433 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted hadoop job: job_local1139006066_0005
2016-01-14 21:11:43,433 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tracking url: http://localhost:8080/
2016-01-14 21:11:43,446 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt
2016-01-14 21:11:43,455 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:11:43,455 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:11:43,464 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BB902B50BB7340908D7155D9A2C60CF6, ordinal: 0
2016-01-14 21:11:43,465 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:11:43,466 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-01-14 21:11:43,466 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BB902B50BB7340908D7155D9A2C60CF6, mem on start (mb), free: 182, total: 281, max: 672
2016-01-14 21:11:43,470 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BB902B50BB7340908D7155D9A2C60CF6, mem on close (mb), free: 182, total: 281, max: 672
2016-01-14 21:11:43,492 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first/_temporary
2016-01-14 21:11:43,493 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  completed in: 00:00.190
2016-01-14 21:11:43,494 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: first
2016-01-14 21:11:43,495 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: second
2016-01-14 21:11:43,495 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] at least one sink is marked for delete
2016-01-14 21:11:43,495 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:11:43,500 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting
2016-01-14 21:11:43,501 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-01-14 21:11:43,501 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-01-14 21:11:43,502 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  parallel execution of steps is enabled: false
2016-01-14 21:11:43,502 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  executing total steps: 1
2016-01-14 21:11:43,503 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  allocating management threads: 1
2016-01-14 21:11:43,504 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting step: (1/1) ...e/perpetualcascade/second
2016-01-14 21:11:43,586 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1290302320/.staging/job_local1290302320_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:43,587 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1290302320/.staging/job_local1290302320_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:43,652 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1290302320_0006/job_local1290302320_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:43,652 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1290302320_0006/job_local1290302320_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:43,653 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] submitted hadoop job: job_local1290302320_0006
2016-01-14 21:11:43,653 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] tracking url: http://localhost:8080/
2016-01-14 21:11:43,661 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first/part-00000
2016-01-14 21:11:43,669 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:11:43,669 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:11:43,677 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B2EAED4F45B94F1581A96F643C02F281, ordinal: 0
2016-01-14 21:11:43,678 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-01-14 21:11:43,678 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-01-14 21:11:43,679 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B2EAED4F45B94F1581A96F643C02F281, mem on start (mb), free: 263, total: 281, max: 672
2016-01-14 21:11:43,682 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B2EAED4F45B94F1581A96F643C02F281, mem on close (mb), free: 263, total: 281, max: 672
2016-01-14 21:11:43,701 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second/_temporary
2016-01-14 21:11:43,701 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  completed in: 00:00.200
2016-01-14 21:11:43,701 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: second
2016-01-14 21:11:43,702 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: third
2016-01-14 21:11:43,702 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] at least one sink is marked for delete
2016-01-14 21:11:43,703 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:11:43,706 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting
2016-01-14 21:11:43,706 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-01-14 21:11:43,707 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-01-14 21:11:43,707 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  parallel execution of steps is enabled: false
2016-01-14 21:11:43,708 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  executing total steps: 1
2016-01-14 21:11:43,708 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  allocating management threads: 1
2016-01-14 21:11:43,709 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting step: (1/1) ...de/perpetualcascade/third
2016-01-14 21:11:43,781 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity496991285/.staging/job_local496991285_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:43,784 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity496991285/.staging/job_local496991285_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:43,825 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local496991285_0007/job_local496991285_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:43,825 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local496991285_0007/job_local496991285_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:43,826 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] submitted hadoop job: job_local496991285_0007
2016-01-14 21:11:43,826 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] tracking url: http://localhost:8080/
2016-01-14 21:11:43,832 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second/part-00000
2016-01-14 21:11:43,840 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:11:43,840 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:11:43,847 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CCC062EA93F7413AA771247308DF6B13, ordinal: 0
2016-01-14 21:11:43,848 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-01-14 21:11:43,849 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-01-14 21:11:43,849 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CCC062EA93F7413AA771247308DF6B13, mem on start (mb), free: 231, total: 281, max: 672
2016-01-14 21:11:43,853 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CCC062EA93F7413AA771247308DF6B13, mem on close (mb), free: 231, total: 281, max: 672
2016-01-14 21:11:43,871 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third/_temporary
2016-01-14 21:11:43,872 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  completed in: 00:00.165
2016-01-14 21:11:43,872 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: third
2016-01-14 21:11:43,873 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: fourth
2016-01-14 21:11:43,873 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] at least one sink is marked for delete
2016-01-14 21:11:43,873 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:11:43,880 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting
2016-01-14 21:11:43,880 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-01-14 21:11:43,881 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth"]
2016-01-14 21:11:43,881 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  parallel execution of steps is enabled: false
2016-01-14 21:11:43,881 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  executing total steps: 1
2016-01-14 21:11:43,882 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  allocating management threads: 1
2016-01-14 21:11:43,882 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting step: (1/1) ...e/perpetualcascade/fourth
2016-01-14 21:11:43,952 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1003411773/.staging/job_local1003411773_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:43,953 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1003411773/.staging/job_local1003411773_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:43,990 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1003411773_0008/job_local1003411773_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 21:11:43,991 WARN  conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1003411773_0008/job_local1003411773_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 21:11:43,991 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] submitted hadoop job: job_local1003411773_0008
2016-01-14 21:11:43,992 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] tracking url: http://localhost:8080/
2016-01-14 21:11:43,998 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third/part-00000
2016-01-14 21:11:44,005 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 21:11:44,005 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 21:11:44,013 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C0E592D2537848939A5185797C596085, ordinal: 0
2016-01-14 21:11:44,013 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-01-14 21:11:44,014 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth"]
2016-01-14 21:11:44,014 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C0E592D2537848939A5185797C596085, mem on start (mb), free: 199, total: 281, max: 672
2016-01-14 21:11:44,016 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C0E592D2537848939A5185797C596085, mem on close (mb), free: 199, total: 281, max: 672
2016-01-14 21:11:44,037 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth/_temporary
2016-01-14 21:11:44,038 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  completed in: 00:00.157
2016-01-14 21:11:44,038 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: fourth
2016-01-14 21:11:44,065 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third
2016-01-14 21:11:44,066 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first
2016-01-14 21:11:44,066 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth
2016-01-14 21:11:44,066 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second
2016-01-14 21:11:44,073 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowWithCounters/counter/first
2016-01-14 21:11:44,078 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInComplete/completeException/first
2016-01-14 21:11:44,084 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInStart/startException/first