Class cascading.cascade.RiffleCascadePlatformTest

7

tests

0

failures

0

ignored

4.231s

duration

100%

successful

Tests

Test Duration Result
testProcessFlowFlowListenerExceptionHandlingInComplete 0.007s passed
testProcessFlowFlowListenerExceptionHandlingInStart 0.004s passed
testProcessFlowFlowListenerExceptionHandlingInStop 0.010s passed
testProcessFlowWithChildCounters 0.727s passed
testProcessFlowWithCounters 0.006s passed
testSimpleRiffle 2.464s passed
testSimpleRiffleCascade 1.013s passed

Standard output

2016-05-18 00:28:54,197 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 00:28:54,218 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.cascade.RiffleCascadePlatformTest, with platform: hadoop2-mr1
2016-05-18 00:28:54,240 INFO  hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-18 00:28:54,737 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 00:28:54,880 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides: 
2016-05-18 00:28:54,926 INFO  property.AppProps (AppProps.java:getAppID(177)) - using app.id: DE108532A1564A64AE5BCEB40310578A
2016-05-18 00:28:54,964 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowWithChildCounters/children/first
2016-05-18 00:28:54,976 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInStop/stopException/first
2016-05-18 00:28:55,046 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:28:55,048 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 00:28:55,241 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.081
2016-05-18 00:28:55,244 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:28:55,244 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:28:55,375 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:28:55,376 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 00:28:55,430 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.045
2016-05-18 00:28:55,432 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:28:55,433 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:28:55,472 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:28:55,473 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 00:28:55,523 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.043
2016-05-18 00:28:55,524 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:28:55,524 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:28:55,564 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:28:55,565 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 00:28:55,625 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.051
2016-05-18 00:28:55,626 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:28:55,627 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:28:55,726 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 00:28:55,728 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-18 00:28:55,728 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:28:55,729 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-05-18 00:28:55,729 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  parallel execution of steps is enabled: false
2016-05-18 00:28:55,729 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  executing total steps: 1
2016-05-18 00:28:55,730 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  allocating management threads: 1
2016-05-18 00:28:55,731 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...pleRiffle/perpetual/first
2016-05-18 00:28:56,222 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1451068797/.staging/job_local1451068797_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:56,223 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1451068797/.staging/job_local1451068797_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:56,377 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1451068797_0001/job_local1451068797_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:56,378 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1451068797_0001/job_local1451068797_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:56,391 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted hadoop job: job_local1451068797_0001
2016-05-18 00:28:56,392 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tracking url: http://localhost:8080/
2016-05-18 00:28:56,491 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/ips.20.txt
2016-05-18 00:28:56,513 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:28:56,513 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:28:56,535 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D7DC1E1E14F54586B61E61077B3610FA, ordinal: 0
2016-05-18 00:28:56,582 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:28:56,582 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-05-18 00:28:56,584 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D7DC1E1E14F54586B61E61077B3610FA, mem on start (mb), free: 223, total: 281, max: 672
2016-05-18 00:28:56,601 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D7DC1E1E14F54586B61E61077B3610FA, mem on close (mb), free: 222, total: 281, max: 672
2016-05-18 00:28:56,642 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first/_temporary
2016-05-18 00:28:56,642 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  completed in: 00:00.912
2016-05-18 00:28:56,645 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting
2016-05-18 00:28:56,645 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-05-18 00:28:56,645 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-05-18 00:28:56,645 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  parallel execution of steps is enabled: false
2016-05-18 00:28:56,646 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  executing total steps: 1
2016-05-18 00:28:56,646 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  allocating management threads: 1
2016-05-18 00:28:56,647 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting step: (1/1) ...leRiffle/perpetual/second
2016-05-18 00:28:56,750 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1136380836/.staging/job_local1136380836_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:56,750 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1136380836/.staging/job_local1136380836_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:56,831 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1136380836_0002/job_local1136380836_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:56,832 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1136380836_0002/job_local1136380836_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:56,834 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] submitted hadoop job: job_local1136380836_0002
2016-05-18 00:28:56,834 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] tracking url: http://localhost:8080/
2016-05-18 00:28:56,843 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first/part-00000
2016-05-18 00:28:56,852 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:28:56,852 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:28:56,862 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D9653AA039ED43F29846E44BF66E3B58, ordinal: 0
2016-05-18 00:28:56,863 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-05-18 00:28:56,864 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-05-18 00:28:56,864 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D9653AA039ED43F29846E44BF66E3B58, mem on start (mb), free: 186, total: 281, max: 672
2016-05-18 00:28:56,870 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D9653AA039ED43F29846E44BF66E3B58, mem on close (mb), free: 186, total: 281, max: 672
2016-05-18 00:28:56,889 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second/_temporary
2016-05-18 00:28:56,890 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  completed in: 00:00.244
2016-05-18 00:28:56,893 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting
2016-05-18 00:28:56,893 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-05-18 00:28:56,893 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-05-18 00:28:56,894 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  parallel execution of steps is enabled: false
2016-05-18 00:28:56,894 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  executing total steps: 1
2016-05-18 00:28:56,894 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  allocating management threads: 1
2016-05-18 00:28:56,895 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting step: (1/1) ...pleRiffle/perpetual/third
2016-05-18 00:28:57,012 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity918955906/.staging/job_local918955906_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:57,012 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity918955906/.staging/job_local918955906_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:57,109 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local918955906_0003/job_local918955906_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:57,110 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local918955906_0003/job_local918955906_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:57,111 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] submitted hadoop job: job_local918955906_0003
2016-05-18 00:28:57,112 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] tracking url: http://localhost:8080/
2016-05-18 00:28:57,117 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second/part-00000
2016-05-18 00:28:57,126 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:28:57,126 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:28:57,136 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F3909090C5464BBBA02C6E767B89ABB5, ordinal: 0
2016-05-18 00:28:57,137 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-05-18 00:28:57,137 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-05-18 00:28:57,138 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F3909090C5464BBBA02C6E767B89ABB5, mem on start (mb), free: 265, total: 281, max: 672
2016-05-18 00:28:57,142 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F3909090C5464BBBA02C6E767B89ABB5, mem on close (mb), free: 264, total: 281, max: 672
2016-05-18 00:28:57,166 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third/_temporary
2016-05-18 00:28:57,166 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  completed in: 00:00.273
2016-05-18 00:28:57,168 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting
2016-05-18 00:28:57,169 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-05-18 00:28:57,169 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth"]
2016-05-18 00:28:57,169 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  parallel execution of steps is enabled: false
2016-05-18 00:28:57,169 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  executing total steps: 1
2016-05-18 00:28:57,169 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  allocating management threads: 1
2016-05-18 00:28:57,170 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting step: (1/1) ...leRiffle/perpetual/fourth
2016-05-18 00:28:57,287 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity74879516/.staging/job_local74879516_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:57,288 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity74879516/.staging/job_local74879516_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:57,344 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local74879516_0004/job_local74879516_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:57,344 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local74879516_0004/job_local74879516_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:57,345 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] submitted hadoop job: job_local74879516_0004
2016-05-18 00:28:57,345 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] tracking url: http://localhost:8080/
2016-05-18 00:28:57,353 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third/part-00000
2016-05-18 00:28:57,368 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:28:57,368 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:28:57,380 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FFB04EDF98864776AA73ED497463FDA0, ordinal: 0
2016-05-18 00:28:57,381 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-05-18 00:28:57,381 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth"]
2016-05-18 00:28:57,381 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FFB04EDF98864776AA73ED497463FDA0, mem on start (mb), free: 231, total: 281, max: 672
2016-05-18 00:28:57,385 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FFB04EDF98864776AA73ED497463FDA0, mem on close (mb), free: 231, total: 281, max: 672
2016-05-18 00:28:57,403 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth/_temporary
2016-05-18 00:28:57,403 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  completed in: 00:00.234
2016-05-18 00:28:57,440 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second
2016-05-18 00:28:57,440 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third
2016-05-18 00:28:57,440 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first
2016-05-18 00:28:57,441 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth
2016-05-18 00:28:57,461 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:28:57,461 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 00:28:57,497 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.030
2016-05-18 00:28:57,499 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:28:57,499 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:28:57,527 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:28:57,528 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 00:28:57,560 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-05-18 00:28:57,561 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:28:57,561 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:28:57,585 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:28:57,586 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 00:28:57,615 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-05-18 00:28:57,616 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:28:57,617 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:28:57,640 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 00:28:57,640 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 00:28:57,670 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.024
2016-05-18 00:28:57,670 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 00:28:57,671 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 00:28:57,701 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting
2016-05-18 00:28:57,703 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third]  parallel execution of flows is enabled: false
2016-05-18 00:28:57,703 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third]  executing total flows: 4
2016-05-18 00:28:57,703 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third]  allocating management threads: 1
2016-05-18 00:28:57,704 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: first
2016-05-18 00:28:57,705 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] at least one sink is marked for delete
2016-05-18 00:28:57,708 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 00:28:57,711 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-18 00:28:57,711 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:28:57,711 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-05-18 00:28:57,712 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  parallel execution of steps is enabled: false
2016-05-18 00:28:57,712 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  executing total steps: 1
2016-05-18 00:28:57,712 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  allocating management threads: 1
2016-05-18 00:28:57,714 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...de/perpetualcascade/first
2016-05-18 00:28:57,784 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1130345971/.staging/job_local1130345971_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:57,785 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1130345971/.staging/job_local1130345971_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:57,832 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1130345971_0005/job_local1130345971_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:57,832 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1130345971_0005/job_local1130345971_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:57,833 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted hadoop job: job_local1130345971_0005
2016-05-18 00:28:57,834 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tracking url: http://localhost:8080/
2016-05-18 00:28:57,840 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/ips.20.txt
2016-05-18 00:28:57,849 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:28:57,849 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:28:57,860 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AB330BB4D7484AA38E630606B668D92E, ordinal: 0
2016-05-18 00:28:57,861 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/ips.20.txt"]
2016-05-18 00:28:57,861 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-05-18 00:28:57,862 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AB330BB4D7484AA38E630606B668D92E, mem on start (mb), free: 167, total: 281, max: 672
2016-05-18 00:28:57,865 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AB330BB4D7484AA38E630606B668D92E, mem on close (mb), free: 167, total: 281, max: 672
2016-05-18 00:28:57,890 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first/_temporary
2016-05-18 00:28:57,891 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  completed in: 00:00.179
2016-05-18 00:28:57,891 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: first
2016-05-18 00:28:57,892 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: second
2016-05-18 00:28:57,892 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] at least one sink is marked for delete
2016-05-18 00:28:57,892 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 00:28:57,900 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting
2016-05-18 00:28:57,900 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-05-18 00:28:57,900 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-05-18 00:28:57,900 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  parallel execution of steps is enabled: false
2016-05-18 00:28:57,901 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  executing total steps: 1
2016-05-18 00:28:57,901 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  allocating management threads: 1
2016-05-18 00:28:57,902 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting step: (1/1) ...e/perpetualcascade/second
2016-05-18 00:28:58,012 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1173003423/.staging/job_local1173003423_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:58,012 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1173003423/.staging/job_local1173003423_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:58,052 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1173003423_0006/job_local1173003423_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:58,053 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1173003423_0006/job_local1173003423_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:58,053 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] submitted hadoop job: job_local1173003423_0006
2016-05-18 00:28:58,054 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] tracking url: http://localhost:8080/
2016-05-18 00:28:58,061 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first/part-00000
2016-05-18 00:28:58,069 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:28:58,070 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:28:58,079 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B6E5B141AE9B46A1B46D2ABD419FA1BC, ordinal: 0
2016-05-18 00:28:58,080 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-05-18 00:28:58,080 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-05-18 00:28:58,080 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B6E5B141AE9B46A1B46D2ABD419FA1BC, mem on start (mb), free: 364, total: 397, max: 672
2016-05-18 00:28:58,084 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B6E5B141AE9B46A1B46D2ABD419FA1BC, mem on close (mb), free: 364, total: 397, max: 672
2016-05-18 00:28:58,102 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second/_temporary
2016-05-18 00:28:58,102 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  completed in: 00:00.201
2016-05-18 00:28:58,102 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: second
2016-05-18 00:28:58,103 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: third
2016-05-18 00:28:58,103 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] at least one sink is marked for delete
2016-05-18 00:28:58,104 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 00:28:58,108 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting
2016-05-18 00:28:58,108 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-05-18 00:28:58,109 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-05-18 00:28:58,109 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  parallel execution of steps is enabled: false
2016-05-18 00:28:58,110 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  executing total steps: 1
2016-05-18 00:28:58,110 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  allocating management threads: 1
2016-05-18 00:28:58,111 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting step: (1/1) ...de/perpetualcascade/third
2016-05-18 00:28:58,189 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1263388472/.staging/job_local1263388472_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:58,189 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1263388472/.staging/job_local1263388472_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:58,227 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1263388472_0007/job_local1263388472_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:58,227 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1263388472_0007/job_local1263388472_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:58,229 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] submitted hadoop job: job_local1263388472_0007
2016-05-18 00:28:58,229 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] tracking url: http://localhost:8080/
2016-05-18 00:28:58,235 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second/part-00000
2016-05-18 00:28:58,242 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:28:58,242 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:28:58,249 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A1101F77E9ED4CA39434991FBDCEA9F2, ordinal: 0
2016-05-18 00:28:58,250 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-05-18 00:28:58,250 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-05-18 00:28:58,250 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A1101F77E9ED4CA39434991FBDCEA9F2, mem on start (mb), free: 325, total: 397, max: 672
2016-05-18 00:28:58,255 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A1101F77E9ED4CA39434991FBDCEA9F2, mem on close (mb), free: 325, total: 397, max: 672
2016-05-18 00:28:58,275 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third/_temporary
2016-05-18 00:28:58,276 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  completed in: 00:00.167
2016-05-18 00:28:58,276 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: third
2016-05-18 00:28:58,277 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: fourth
2016-05-18 00:28:58,277 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] at least one sink is marked for delete
2016-05-18 00:28:58,277 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 00:28:58,280 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting
2016-05-18 00:28:58,281 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-05-18 00:28:58,281 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth"]
2016-05-18 00:28:58,281 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  parallel execution of steps is enabled: false
2016-05-18 00:28:58,281 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  executing total steps: 1
2016-05-18 00:28:58,281 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  allocating management threads: 1
2016-05-18 00:28:58,283 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting step: (1/1) ...e/perpetualcascade/fourth
2016-05-18 00:28:58,347 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1695878724/.staging/job_local1695878724_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:58,348 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1695878724/.staging/job_local1695878724_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:58,383 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1695878724_0008/job_local1695878724_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-18 00:28:58,384 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1695878724_0008/job_local1695878724_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-18 00:28:58,385 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] submitted hadoop job: job_local1695878724_0008
2016-05-18 00:28:58,385 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] tracking url: http://localhost:8080/
2016-05-18 00:28:58,390 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third/part-00000
2016-05-18 00:28:58,397 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 00:28:58,397 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 00:28:58,405 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E1B1E5F4CE9E4C41A419866EE58EB778, ordinal: 0
2016-05-18 00:28:58,406 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-05-18 00:28:58,406 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth"]
2016-05-18 00:28:58,406 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E1B1E5F4CE9E4C41A419866EE58EB778, mem on start (mb), free: 286, total: 397, max: 672
2016-05-18 00:28:58,409 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E1B1E5F4CE9E4C41A419866EE58EB778, mem on close (mb), free: 286, total: 397, max: 672
2016-05-18 00:28:58,430 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth/_temporary
2016-05-18 00:28:58,430 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  completed in: 00:00.149
2016-05-18 00:28:58,430 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: fourth
2016-05-18 00:28:58,455 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth
2016-05-18 00:28:58,456 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second
2016-05-18 00:28:58,456 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third
2016-05-18 00:28:58,456 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first
2016-05-18 00:28:58,461 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowWithCounters/counter/first
2016-05-18 00:28:58,468 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInComplete/completeException/first
2016-05-18 00:28:58,473 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInStart/startException/first