2016-05-17 22:09:02,352 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-17 22:09:02,374 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.cascade.RiffleCascadePlatformTest, with platform: hadoop2-mr1
2016-05-17 22:09:02,399 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-17 22:09:02,941 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-17 22:09:03,048 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-17 22:09:03,096 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: B21594ED1B584C45A281D5C233781BA6
2016-05-17 22:09:03,136 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowWithChildCounters/children/first
2016-05-17 22:09:03,148 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInStop/stopException/first
2016-05-17 22:09:03,214 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:09:03,217 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-17 22:09:03,416 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.085
2016-05-17 22:09:03,419 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 22:09:03,419 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-17 22:09:03,569 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:09:03,570 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-17 22:09:03,630 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.051
2016-05-17 22:09:03,633 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 22:09:03,633 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-17 22:09:03,676 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:09:03,676 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-17 22:09:03,726 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.040
2016-05-17 22:09:03,727 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 22:09:03,727 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-17 22:09:03,766 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:09:03,767 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-17 22:09:03,831 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.056
2016-05-17 22:09:03,833 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 22:09:03,833 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-17 22:09:03,916 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-17 22:09:03,917 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-17 22:09:03,918 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.2.x/build/classes/test/data/ips.20.txt"]
2016-05-17 22:09:03,918 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-05-17 22:09:03,918 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] parallel execution of steps is enabled: false
2016-05-17 22:09:03,918 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executing total steps: 1
2016-05-17 22:09:03,918 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] allocating management threads: 1
2016-05-17 22:09:03,919 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...pleRiffle/perpetual/first
2016-05-17 22:09:04,402 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1285877708/.staging/job_local1285877708_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:04,413 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1285877708/.staging/job_local1285877708_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:04,514 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1285877708_0001/job_local1285877708_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:04,515 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1285877708_0001/job_local1285877708_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:04,525 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted hadoop job: job_local1285877708_0001
2016-05-17 22:09:04,526 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tracking url: http://localhost:8080/
2016-05-17 22:09:04,593 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/classes/test/data/ips.20.txt
2016-05-17 22:09:04,613 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:09:04,613 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:09:04,629 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BBB57F3DAC76472E8A54B25BFE8E189B, ordinal: 0
2016-05-17 22:09:04,676 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.2.x/build/classes/test/data/ips.20.txt"]
2016-05-17 22:09:04,678 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-05-17 22:09:04,679 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBB57F3DAC76472E8A54B25BFE8E189B, mem on start (mb), free: 231, total: 281, max: 672
2016-05-17 22:09:04,696 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBB57F3DAC76472E8A54B25BFE8E189B, mem on close (mb), free: 230, total: 281, max: 672
2016-05-17 22:09:04,747 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first/_temporary
2016-05-17 22:09:04,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] completed in: 00:00.828
2016-05-17 22:09:04,750 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting
2016-05-17 22:09:04,751 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-05-17 22:09:04,751 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-05-17 22:09:04,752 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] parallel execution of steps is enabled: false
2016-05-17 22:09:04,753 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executing total steps: 1
2016-05-17 22:09:04,754 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] allocating management threads: 1
2016-05-17 22:09:04,754 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting step: (1/1) ...leRiffle/perpetual/second
2016-05-17 22:09:04,850 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1435792839/.staging/job_local1435792839_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:04,852 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1435792839/.staging/job_local1435792839_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:04,909 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1435792839_0002/job_local1435792839_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:04,910 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1435792839_0002/job_local1435792839_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:04,911 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] submitted hadoop job: job_local1435792839_0002
2016-05-17 22:09:04,912 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] tracking url: http://localhost:8080/
2016-05-17 22:09:04,918 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first/part-00000
2016-05-17 22:09:04,928 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:09:04,928 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:09:04,938 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C87DA55237EB4C24B9F56198B09C029C, ordinal: 0
2016-05-17 22:09:04,939 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first"]
2016-05-17 22:09:04,940 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-05-17 22:09:04,941 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C87DA55237EB4C24B9F56198B09C029C, mem on start (mb), free: 196, total: 281, max: 672
2016-05-17 22:09:04,946 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C87DA55237EB4C24B9F56198B09C029C, mem on close (mb), free: 196, total: 281, max: 672
2016-05-17 22:09:04,967 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second/_temporary
2016-05-17 22:09:04,968 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] completed in: 00:00.217
2016-05-17 22:09:04,969 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting
2016-05-17 22:09:04,970 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-05-17 22:09:04,970 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-05-17 22:09:04,971 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] parallel execution of steps is enabled: false
2016-05-17 22:09:04,972 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executing total steps: 1
2016-05-17 22:09:04,972 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] allocating management threads: 1
2016-05-17 22:09:04,973 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting step: (1/1) ...pleRiffle/perpetual/third
2016-05-17 22:09:05,134 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity410489504/.staging/job_local410489504_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:05,138 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity410489504/.staging/job_local410489504_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:05,205 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local410489504_0003/job_local410489504_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:05,206 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local410489504_0003/job_local410489504_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:05,207 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] submitted hadoop job: job_local410489504_0003
2016-05-17 22:09:05,208 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] tracking url: http://localhost:8080/
2016-05-17 22:09:05,215 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second/part-00000
2016-05-17 22:09:05,229 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:09:05,229 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:09:05,243 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B26D3EA9D67C4E3F94F12E5A84A38733, ordinal: 0
2016-05-17 22:09:05,244 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second"]
2016-05-17 22:09:05,244 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-05-17 22:09:05,244 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B26D3EA9D67C4E3F94F12E5A84A38733, mem on start (mb), free: 164, total: 281, max: 672
2016-05-17 22:09:05,249 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B26D3EA9D67C4E3F94F12E5A84A38733, mem on close (mb), free: 163, total: 281, max: 672
2016-05-17 22:09:05,269 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third/_temporary
2016-05-17 22:09:05,269 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] completed in: 00:00.299
2016-05-17 22:09:05,271 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting
2016-05-17 22:09:05,272 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-05-17 22:09:05,274 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.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth"]
2016-05-17 22:09:05,275 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] parallel execution of steps is enabled: false
2016-05-17 22:09:05,276 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executing total steps: 1
2016-05-17 22:09:05,277 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] allocating management threads: 1
2016-05-17 22:09:05,286 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting step: (1/1) ...leRiffle/perpetual/fourth
2016-05-17 22:09:05,408 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1055859754/.staging/job_local1055859754_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:05,412 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1055859754/.staging/job_local1055859754_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:05,454 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1055859754_0004/job_local1055859754_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:05,455 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1055859754_0004/job_local1055859754_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:05,456 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] submitted hadoop job: job_local1055859754_0004
2016-05-17 22:09:05,457 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] tracking url: http://localhost:8080/
2016-05-17 22:09:05,461 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third/part-00000
2016-05-17 22:09:05,472 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:09:05,473 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:09:05,488 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DC6B2D2B6F164AD7842292109CAF8142, ordinal: 0
2016-05-17 22:09:05,489 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third"]
2016-05-17 22:09:05,490 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.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth"]
2016-05-17 22:09:05,490 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DC6B2D2B6F164AD7842292109CAF8142, mem on start (mb), free: 246, total: 281, max: 672
2016-05-17 22:09:05,493 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DC6B2D2B6F164AD7842292109CAF8142, mem on close (mb), free: 245, total: 281, max: 672
2016-05-17 22:09:05,513 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth/_temporary
2016-05-17 22:09:05,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] completed in: 00:00.242
2016-05-17 22:09:05,563 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/fourth
2016-05-17 22:09:05,563 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/second
2016-05-17 22:09:05,564 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/first
2016-05-17 22:09:05,564 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffle/perpetual/third
2016-05-17 22:09:05,595 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:09:05,596 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-17 22:09:05,652 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.046
2016-05-17 22:09:05,653 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 22:09:05,653 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-17 22:09:05,685 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:09:05,685 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-17 22:09:05,726 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-05-17 22:09:05,727 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 22:09:05,728 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-17 22:09:05,752 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:09:05,753 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-17 22:09:05,783 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-05-17 22:09:05,785 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 22:09:05,785 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-17 22:09:05,809 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 22:09:05,809 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-17 22:09:05,839 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-05-17 22:09:05,840 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 22:09:05,841 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-17 22:09:05,868 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting
2016-05-17 22:09:05,870 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] parallel execution of flows is enabled: false
2016-05-17 22:09:05,870 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] executing total flows: 4
2016-05-17 22:09:05,871 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] allocating management threads: 1
2016-05-17 22:09:05,871 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: first
2016-05-17 22:09:05,872 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] at least one sink is marked for delete
2016-05-17 22:09:05,875 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 22:09:05,877 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-17 22:09:05,877 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.2.x/build/classes/test/data/ips.20.txt"]
2016-05-17 22:09:05,877 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-05-17 22:09:05,879 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] parallel execution of steps is enabled: false
2016-05-17 22:09:05,879 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executing total steps: 1
2016-05-17 22:09:05,879 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] allocating management threads: 1
2016-05-17 22:09:05,881 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...de/perpetualcascade/first
2016-05-17 22:09:05,953 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity761576253/.staging/job_local761576253_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:05,955 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity761576253/.staging/job_local761576253_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:05,999 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local761576253_0005/job_local761576253_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:05,999 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local761576253_0005/job_local761576253_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:06,000 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted hadoop job: job_local761576253_0005
2016-05-17 22:09:06,000 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tracking url: http://localhost:8080/
2016-05-17 22:09:06,008 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/classes/test/data/ips.20.txt
2016-05-17 22:09:06,016 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:09:06,016 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:09:06,026 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BD5EA5D065F34AF7B59E4E679C4AA2DA, ordinal: 0
2016-05-17 22:09:06,027 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.2.x/build/classes/test/data/ips.20.txt"]
2016-05-17 22:09:06,027 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-05-17 22:09:06,027 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BD5EA5D065F34AF7B59E4E679C4AA2DA, mem on start (mb), free: 181, total: 281, max: 672
2016-05-17 22:09:06,030 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BD5EA5D065F34AF7B59E4E679C4AA2DA, mem on close (mb), free: 181, total: 281, max: 672
2016-05-17 22:09:06,059 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first/_temporary
2016-05-17 22:09:06,059 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first] completed in: 00:00.181
2016-05-17 22:09:06,060 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: first
2016-05-17 22:09:06,060 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: second
2016-05-17 22:09:06,060 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] at least one sink is marked for delete
2016-05-17 22:09:06,060 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 22:09:06,063 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting
2016-05-17 22:09:06,063 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-05-17 22:09:06,064 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-05-17 22:09:06,064 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] parallel execution of steps is enabled: false
2016-05-17 22:09:06,064 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executing total steps: 1
2016-05-17 22:09:06,064 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] allocating management threads: 1
2016-05-17 22:09:06,065 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting step: (1/1) ...e/perpetualcascade/second
2016-05-17 22:09:06,138 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity442715539/.staging/job_local442715539_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:06,139 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity442715539/.staging/job_local442715539_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:06,210 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local442715539_0006/job_local442715539_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:06,210 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local442715539_0006/job_local442715539_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:06,211 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] submitted hadoop job: job_local442715539_0006
2016-05-17 22:09:06,211 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] tracking url: http://localhost:8080/
2016-05-17 22:09:06,217 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first/part-00000
2016-05-17 22:09:06,225 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:09:06,225 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:09:06,236 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A973B6AFFDEB48389C522C741BCB706C, ordinal: 0
2016-05-17 22:09:06,236 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first"]
2016-05-17 22:09:06,237 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-05-17 22:09:06,237 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A973B6AFFDEB48389C522C741BCB706C, mem on start (mb), free: 379, total: 397, max: 672
2016-05-17 22:09:06,240 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A973B6AFFDEB48389C522C741BCB706C, mem on close (mb), free: 379, total: 397, max: 672
2016-05-17 22:09:06,270 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second/_temporary
2016-05-17 22:09:06,271 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second] completed in: 00:00.207
2016-05-17 22:09:06,271 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: second
2016-05-17 22:09:06,272 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: third
2016-05-17 22:09:06,272 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] at least one sink is marked for delete
2016-05-17 22:09:06,272 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 22:09:06,275 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting
2016-05-17 22:09:06,275 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-05-17 22:09:06,275 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-05-17 22:09:06,276 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] parallel execution of steps is enabled: false
2016-05-17 22:09:06,276 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executing total steps: 1
2016-05-17 22:09:06,276 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] allocating management threads: 1
2016-05-17 22:09:06,277 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting step: (1/1) ...de/perpetualcascade/third
2016-05-17 22:09:06,349 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1144717156/.staging/job_local1144717156_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:06,351 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1144717156/.staging/job_local1144717156_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:06,387 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1144717156_0007/job_local1144717156_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:06,387 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1144717156_0007/job_local1144717156_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:06,389 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] submitted hadoop job: job_local1144717156_0007
2016-05-17 22:09:06,389 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] tracking url: http://localhost:8080/
2016-05-17 22:09:06,395 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second/part-00000
2016-05-17 22:09:06,402 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:09:06,402 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:09:06,410 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A3BB6AF6BC654872A8C0969A988E06E3, ordinal: 0
2016-05-17 22:09:06,411 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second"]
2016-05-17 22:09:06,411 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-05-17 22:09:06,411 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A3BB6AF6BC654872A8C0969A988E06E3, mem on start (mb), free: 340, total: 397, max: 672
2016-05-17 22:09:06,415 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A3BB6AF6BC654872A8C0969A988E06E3, mem on close (mb), free: 340, total: 397, max: 672
2016-05-17 22:09:06,437 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third/_temporary
2016-05-17 22:09:06,438 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [third] completed in: 00:00.161
2016-05-17 22:09:06,438 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: third
2016-05-17 22:09:06,439 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] starting flow: fourth
2016-05-17 22:09:06,439 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] at least one sink is marked for delete
2016-05-17 22:09:06,439 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-17 22:09:06,441 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting
2016-05-17 22:09:06,441 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-05-17 22:09:06,442 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.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth"]
2016-05-17 22:09:06,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] parallel execution of steps is enabled: false
2016-05-17 22:09:06,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executing total steps: 1
2016-05-17 22:09:06,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] allocating management threads: 1
2016-05-17 22:09:06,443 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting step: (1/1) ...e/perpetualcascade/fourth
2016-05-17 22:09:06,507 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1566933705/.staging/job_local1566933705_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:06,508 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/tmp/cascading/staging/teamcity1566933705/.staging/job_local1566933705_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:06,542 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1566933705_0008/job_local1566933705_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-17 22:09:06,542 WARN conf.Configuration (Configuration.java:loadProperty(2172)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1566933705_0008/job_local1566933705_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-17 22:09:06,543 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] submitted hadoop job: job_local1566933705_0008
2016-05-17 22:09:06,543 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] tracking url: http://localhost:8080/
2016-05-17 22:09:06,549 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third/part-00000
2016-05-17 22:09:06,557 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 22:09:06,557 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 22:09:06,565 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C93DC913AC7540C0B46C8734D802150E, ordinal: 0
2016-05-17 22:09:06,565 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third"]
2016-05-17 22:09:06,566 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.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth"]
2016-05-17 22:09:06,566 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C93DC913AC7540C0B46C8734D802150E, mem on start (mb), free: 302, total: 397, max: 672
2016-05-17 22:09:06,569 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C93DC913AC7540C0B46C8734D802150E, mem on close (mb), free: 302, total: 397, max: 672
2016-05-17 22:09:06,592 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output/hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth/_temporary
2016-05-17 22:09:06,593 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] completed in: 00:00.150
2016-05-17 22:09:06,593 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+first+third] completed flow: fourth
2016-05-17 22:09:06,627 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/fourth
2016-05-17 22:09:06,627 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/second
2016-05-17 22:09:06,627 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/third
2016-05-17 22:09:06,628 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testSimpleRiffleCascade/perpetualcascade/first
2016-05-17 22:09:06,636 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowWithCounters/counter/first
2016-05-17 22:09:06,641 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInComplete/completeException/first
2016-05-17 22:09:06,645 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.2.x/build/test/output//hadoop2-mr1/rifflecascadeplatform/testProcessFlowFlowListenerExceptionHandlingInStart/startException/first