Class cascading.cascade.RiffleCascadePlatformTest

7

tests

0

failures

0

ignored

4.538s

duration

100%

successful

Tests

Test Duration Result
testProcessFlowFlowListenerExceptionHandlingInComplete 0.006s passed
testProcessFlowFlowListenerExceptionHandlingInStart 0.004s passed
testProcessFlowFlowListenerExceptionHandlingInStop 0.011s passed
testProcessFlowWithChildCounters 0.918s passed
testProcessFlowWithCounters 0.009s passed
testSimpleRiffle 2.547s passed
testSimpleRiffleCascade 1.043s passed

Standard output

2016-01-14 23:30:47,824 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 23:30:47,847 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.cascade.RiffleCascadePlatformTest, with platform: hadoop2-mr1
2016-01-14 23:30:47,873 INFO  hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-01-14 23:30:48,506 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 23:30:48,684 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides: 
2016-01-14 23:30:48,742 INFO  property.AppProps (AppProps.java:getAppID(177)) - using app.id: CED6091B9C5A419888027749C0663B8E
2016-01-14 23:30:48,787 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowWithChildCounters/children/first
2016-01-14 23:30:48,801 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInStop/stopException/first
2016-01-14 23:30:48,895 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:30:48,898 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 23:30:49,131 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.087
2016-01-14 23:30:49,134 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:30:49,135 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 23:30:49,271 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:30:49,272 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 23:30:49,339 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.055
2016-01-14 23:30:49,341 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:30:49,342 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 23:30:49,387 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:30:49,388 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 23:30:49,438 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.041
2016-01-14 23:30:49,439 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:30:49,439 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 23:30:49,476 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:30:49,476 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 23:30:49,528 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.042
2016-01-14 23:30:49,530 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:30:49,530 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 23:30:49,641 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 23:30:49,643 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 23:30:49,644 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/classes/test/data/ips.20.txt"]
2016-01-14 23:30:49,644 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-01-14 23:30:49,644 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  parallel execution of steps is enabled: false
2016-01-14 23:30:49,645 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  executing total steps: 1
2016-01-14 23:30:49,645 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  allocating management threads: 1
2016-01-14 23:30:49,647 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...pleRiffle/perpetual/first
2016-01-14 23:30:50,114 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity727576845/.staging/job_local727576845_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:50,119 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity727576845/.staging/job_local727576845_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:50,223 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local727576845_0001/job_local727576845_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:50,228 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local727576845_0001/job_local727576845_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:50,235 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted hadoop job: job_local727576845_0001
2016-01-14 23:30:50,235 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tracking url: http://localhost:8080/
2016-01-14 23:30:50,306 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/classes/test/data/ips.20.txt
2016-01-14 23:30:50,327 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:30:50,327 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:30:50,340 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B56BB4E5BB094E47AE2D166C6AE2FAD8, ordinal: 0
2016-01-14 23:30:50,372 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/classes/test/data/ips.20.txt"]
2016-01-14 23:30:50,372 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-01-14 23:30:50,373 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B56BB4E5BB094E47AE2D166C6AE2FAD8, mem on start (mb), free: 166, total: 223, max: 672
2016-01-14 23:30:50,385 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B56BB4E5BB094E47AE2D166C6AE2FAD8, mem on close (mb), free: 166, total: 223, max: 672
2016-01-14 23:30:50,426 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first/_temporary
2016-01-14 23:30:50,426 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  completed in: 00:00.781
2016-01-14 23:30:50,429 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting
2016-01-14 23:30:50,430 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-01-14 23:30:50,430 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-01-14 23:30:50,431 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  parallel execution of steps is enabled: false
2016-01-14 23:30:50,431 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  executing total steps: 1
2016-01-14 23:30:50,431 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  allocating management threads: 1
2016-01-14 23:30:50,433 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting step: (1/1) ...leRiffle/perpetual/second
2016-01-14 23:30:50,549 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity702492599/.staging/job_local702492599_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:50,550 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity702492599/.staging/job_local702492599_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:50,624 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local702492599_0002/job_local702492599_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:50,627 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local702492599_0002/job_local702492599_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:50,627 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] submitted hadoop job: job_local702492599_0002
2016-01-14 23:30:50,628 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] tracking url: http://localhost:8080/
2016-01-14 23:30:50,636 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first/part-00000
2016-01-14 23:30:50,647 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:30:50,647 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:30:50,657 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EA10A47338D94FB0A5F52EA2A1E70A3D, ordinal: 0
2016-01-14 23:30:50,658 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-01-14 23:30:50,658 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-01-14 23:30:50,658 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EA10A47338D94FB0A5F52EA2A1E70A3D, mem on start (mb), free: 190, total: 223, max: 672
2016-01-14 23:30:50,664 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EA10A47338D94FB0A5F52EA2A1E70A3D, mem on close (mb), free: 190, total: 223, max: 672
2016-01-14 23:30:50,688 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second/_temporary
2016-01-14 23:30:50,688 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  completed in: 00:00.259
2016-01-14 23:30:50,691 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting
2016-01-14 23:30:50,692 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-01-14 23:30:50,692 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-01-14 23:30:50,692 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  parallel execution of steps is enabled: false
2016-01-14 23:30:50,692 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  executing total steps: 1
2016-01-14 23:30:50,692 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  allocating management threads: 1
2016-01-14 23:30:50,693 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting step: (1/1) ...pleRiffle/perpetual/third
2016-01-14 23:30:50,904 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity555758913/.staging/job_local555758913_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:50,906 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity555758913/.staging/job_local555758913_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:50,978 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local555758913_0003/job_local555758913_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:50,982 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local555758913_0003/job_local555758913_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:50,983 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] submitted hadoop job: job_local555758913_0003
2016-01-14 23:30:50,984 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] tracking url: http://localhost:8080/
2016-01-14 23:30:50,992 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second/part-00000
2016-01-14 23:30:51,007 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:30:51,007 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:30:51,021 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D02976A912DA4DF08E628951BF03A692, ordinal: 0
2016-01-14 23:30:51,022 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-01-14 23:30:51,022 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-01-14 23:30:51,022 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D02976A912DA4DF08E628951BF03A692, mem on start (mb), free: 158, total: 223, max: 672
2016-01-14 23:30:51,027 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D02976A912DA4DF08E628951BF03A692, mem on close (mb), free: 158, total: 223, max: 672
2016-01-14 23:30:51,054 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third/_temporary
2016-01-14 23:30:51,054 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  completed in: 00:00.362
2016-01-14 23:30:51,062 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting
2016-01-14 23:30:51,062 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-01-14 23:30:51,062 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth"]
2016-01-14 23:30:51,063 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  parallel execution of steps is enabled: false
2016-01-14 23:30:51,063 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  executing total steps: 1
2016-01-14 23:30:51,063 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  allocating management threads: 1
2016-01-14 23:30:51,064 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting step: (1/1) ...leRiffle/perpetual/fourth
2016-01-14 23:30:51,184 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity1169704781/.staging/job_local1169704781_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:51,185 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity1169704781/.staging/job_local1169704781_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:51,239 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1169704781_0004/job_local1169704781_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:51,241 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1169704781_0004/job_local1169704781_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:51,242 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] submitted hadoop job: job_local1169704781_0004
2016-01-14 23:30:51,243 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] tracking url: http://localhost:8080/
2016-01-14 23:30:51,248 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third/part-00000
2016-01-14 23:30:51,258 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:30:51,258 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:30:51,267 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C8ED3A18FEF245CD82E77BE470D5E1E4, ordinal: 0
2016-01-14 23:30:51,268 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-01-14 23:30:51,269 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth"]
2016-01-14 23:30:51,269 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C8ED3A18FEF245CD82E77BE470D5E1E4, mem on start (mb), free: 242, total: 281, max: 672
2016-01-14 23:30:51,273 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C8ED3A18FEF245CD82E77BE470D5E1E4, mem on close (mb), free: 241, total: 281, max: 672
2016-01-14 23:30:51,300 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth/_temporary
2016-01-14 23:30:51,300 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  completed in: 00:00.239
2016-01-14 23:30:51,347 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth
2016-01-14 23:30:51,347 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first
2016-01-14 23:30:51,347 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third
2016-01-14 23:30:51,348 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second
2016-01-14 23:30:51,366 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:30:51,367 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 23:30:51,402 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.030
2016-01-14 23:30:51,403 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:30:51,403 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 23:30:51,429 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:30:51,429 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 23:30:51,462 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-01-14 23:30:51,463 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:30:51,463 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 23:30:51,487 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:30:51,487 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 23:30:51,517 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 23:30:51,518 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:30:51,519 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 23:30:51,541 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:30:51,542 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 23:30:51,571 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 23:30:51,571 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:30:51,572 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 23:30:51,602 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting
2016-01-14 23:30:51,604 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third]  parallel execution of flows is enabled: false
2016-01-14 23:30:51,604 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third]  executing total flows: 4
2016-01-14 23:30:51,604 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third]  allocating management threads: 1
2016-01-14 23:30:51,604 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: first
2016-01-14 23:30:51,605 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] at least one sink is marked for delete
2016-01-14 23:30:51,608 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 23:30:51,612 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 23:30:51,612 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/classes/test/data/ips.20.txt"]
2016-01-14 23:30:51,612 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-01-14 23:30:51,613 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  parallel execution of steps is enabled: false
2016-01-14 23:30:51,613 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  executing total steps: 1
2016-01-14 23:30:51,613 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  allocating management threads: 1
2016-01-14 23:30:51,613 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...de/perpetualcascade/first
2016-01-14 23:30:51,701 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity899068009/.staging/job_local899068009_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:51,702 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity899068009/.staging/job_local899068009_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:51,755 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local899068009_0005/job_local899068009_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:51,757 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local899068009_0005/job_local899068009_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:51,758 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted hadoop job: job_local899068009_0005
2016-01-14 23:30:51,758 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tracking url: http://localhost:8080/
2016-01-14 23:30:51,766 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/classes/test/data/ips.20.txt
2016-01-14 23:30:51,776 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:30:51,777 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:30:51,787 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F2C373C0694943CC9C2EDE00D13FC6D0, ordinal: 0
2016-01-14 23:30:51,788 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/classes/test/data/ips.20.txt"]
2016-01-14 23:30:51,789 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-01-14 23:30:51,789 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F2C373C0694943CC9C2EDE00D13FC6D0, mem on start (mb), free: 174, total: 281, max: 672
2016-01-14 23:30:51,793 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F2C373C0694943CC9C2EDE00D13FC6D0, mem on close (mb), free: 174, total: 281, max: 672
2016-01-14 23:30:51,816 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first/_temporary
2016-01-14 23:30:51,817 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first]  completed in: 00:00.204
2016-01-14 23:30:51,817 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: first
2016-01-14 23:30:51,818 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: second
2016-01-14 23:30:51,818 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] at least one sink is marked for delete
2016-01-14 23:30:51,818 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 23:30:51,824 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting
2016-01-14 23:30:51,824 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-01-14 23:30:51,824 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-01-14 23:30:51,825 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  parallel execution of steps is enabled: false
2016-01-14 23:30:51,826 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  executing total steps: 1
2016-01-14 23:30:51,826 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  allocating management threads: 1
2016-01-14 23:30:51,828 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting step: (1/1) ...e/perpetualcascade/second
2016-01-14 23:30:51,933 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity397194155/.staging/job_local397194155_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:51,934 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity397194155/.staging/job_local397194155_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:51,971 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local397194155_0006/job_local397194155_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:51,972 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local397194155_0006/job_local397194155_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:51,972 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] submitted hadoop job: job_local397194155_0006
2016-01-14 23:30:51,973 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second] tracking url: http://localhost:8080/
2016-01-14 23:30:51,979 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first/part-00000
2016-01-14 23:30:51,990 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:30:51,990 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:30:51,998 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B568C62AAF884F22BB3581E5EE2F9B5D, ordinal: 0
2016-01-14 23:30:51,999 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-01-14 23:30:51,999 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-01-14 23:30:52,000 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B568C62AAF884F22BB3581E5EE2F9B5D, mem on start (mb), free: 255, total: 281, max: 672
2016-01-14 23:30:52,004 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B568C62AAF884F22BB3581E5EE2F9B5D, mem on close (mb), free: 255, total: 281, max: 672
2016-01-14 23:30:52,023 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second/_temporary
2016-01-14 23:30:52,023 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second]  completed in: 00:00.198
2016-01-14 23:30:52,023 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: second
2016-01-14 23:30:52,024 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: third
2016-01-14 23:30:52,024 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] at least one sink is marked for delete
2016-01-14 23:30:52,024 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 23:30:52,028 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting
2016-01-14 23:30:52,029 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-01-14 23:30:52,029 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-01-14 23:30:52,029 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  parallel execution of steps is enabled: false
2016-01-14 23:30:52,029 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  executing total steps: 1
2016-01-14 23:30:52,029 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  allocating management threads: 1
2016-01-14 23:30:52,030 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting step: (1/1) ...de/perpetualcascade/third
2016-01-14 23:30:52,104 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity413707404/.staging/job_local413707404_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:52,105 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity413707404/.staging/job_local413707404_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:52,144 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local413707404_0007/job_local413707404_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:52,145 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local413707404_0007/job_local413707404_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:52,146 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] submitted hadoop job: job_local413707404_0007
2016-01-14 23:30:52,147 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third] tracking url: http://localhost:8080/
2016-01-14 23:30:52,154 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second/part-00000
2016-01-14 23:30:52,162 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:30:52,163 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:30:52,170 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CE2C4466F7284FFDBE03A5B6AB0AA49F, ordinal: 0
2016-01-14 23:30:52,171 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-01-14 23:30:52,171 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-01-14 23:30:52,172 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE2C4466F7284FFDBE03A5B6AB0AA49F, mem on start (mb), free: 220, total: 281, max: 672
2016-01-14 23:30:52,176 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE2C4466F7284FFDBE03A5B6AB0AA49F, mem on close (mb), free: 220, total: 281, max: 672
2016-01-14 23:30:52,194 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third/_temporary
2016-01-14 23:30:52,194 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [third]  completed in: 00:00.165
2016-01-14 23:30:52,195 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: third
2016-01-14 23:30:52,195 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: fourth
2016-01-14 23:30:52,196 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] at least one sink is marked for delete
2016-01-14 23:30:52,196 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 23:30:52,200 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting
2016-01-14 23:30:52,200 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-01-14 23:30:52,200 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth"]
2016-01-14 23:30:52,200 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  parallel execution of steps is enabled: false
2016-01-14 23:30:52,200 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  executing total steps: 1
2016-01-14 23:30:52,201 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  allocating management threads: 1
2016-01-14 23:30:52,201 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting step: (1/1) ...e/perpetualcascade/fourth
2016-01-14 23:30:52,271 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity975827657/.staging/job_local975827657_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:52,272 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/tmp/cascading/staging/teamcity975827657/.staging/job_local975827657_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:52,309 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local975827657_0008/job_local975827657_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-01-14 23:30:52,309 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local975827657_0008/job_local975827657_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-01-14 23:30:52,310 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] submitted hadoop job: job_local975827657_0008
2016-01-14 23:30:52,310 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] tracking url: http://localhost:8080/
2016-01-14 23:30:52,316 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third/part-00000
2016-01-14 23:30:52,324 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:30:52,325 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:30:52,333 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D570B0073A02412599B881CFA3FE166D, ordinal: 0
2016-01-14 23:30:52,334 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-01-14 23:30:52,335 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth"]
2016-01-14 23:30:52,336 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D570B0073A02412599B881CFA3FE166D, mem on start (mb), free: 185, total: 281, max: 672
2016-01-14 23:30:52,339 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D570B0073A02412599B881CFA3FE166D, mem on close (mb), free: 185, total: 281, max: 672
2016-01-14 23:30:52,357 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth/_temporary
2016-01-14 23:30:52,357 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth]  completed in: 00:00.156
2016-01-14 23:30:52,357 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: fourth
2016-01-14 23:30:52,391 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first
2016-01-14 23:30:52,391 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second
2016-01-14 23:30:52,392 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth
2016-01-14 23:30:52,392 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third
2016-01-14 23:30:52,401 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowWithCounters/counter/first
2016-01-14 23:30:52,407 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInComplete/completeException/first
2016-01-14 23:30:52,412 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.5.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInStart/startException/first