2016-05-18 08:36:45,843 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 08:36:45,866 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.scheme.TextDelimitedPlatformTest, with platform: hadoop2-mr1
2016-05-18 08:36:45,891 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-18 08:36:46,559 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 08:36:46,709 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 08:36:46,826 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:36:46,829 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:36:46,911 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 0B082A39274B4CA78CD0327AA1E77B0E
2016-05-18 08:36:47,033 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.076
2016-05-18 08:36:47,036 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:36:47,036 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:36:47,174 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 08:36:47,176 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting
2016-05-18 08:36:47,176 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-spec-char.txt"]
2016-05-18 08:36:47,177 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedTextSpecChar/quoted/speccharfalse"]
2016-05-18 08:36:47,177 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] parallel execution of steps is enabled: false
2016-05-18 08:36:47,178 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executing total steps: 1
2016-05-18 08:36:47,179 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] allocating management threads: 1
2016-05-18 08:36:47,180 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting step: (1/1) ...Char/quoted/speccharfalse
2016-05-18 08:36:47,892 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] submitted hadoop job: job_local662853665_0001
2016-05-18 08:36:47,892 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] tracking url: http://localhost:8080/
2016-05-18 08:36:47,984 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-spec-char.txt
2016-05-18 08:36:48,009 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:36:48,010 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:36:48,027 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E9E9BA550FB64416BEB328ADDBA27E66, ordinal: 0
2016-05-18 08:36:48,058 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-spec-char.txt"]
2016-05-18 08:36:48,058 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedTextSpecChar/quoted/speccharfalse"]
2016-05-18 08:36:48,060 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E9E9BA550FB64416BEB328ADDBA27E66, mem on start (mb), free: 222, total: 281, max: 672
2016-05-18 08:36:48,082 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E9E9BA550FB64416BEB328ADDBA27E66, mem on close (mb), free: 221, total: 281, max: 672
2016-05-18 08:36:48,136 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedTextSpecChar/quoted/speccharfalse/_temporary
2016-05-18 08:36:48,136 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] completed in: 00:00.959
2016-05-18 08:36:48,236 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testQuotedTextSpecChar/quoted/speccharfalse
2016-05-18 08:36:48,265 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:36:48,265 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:36:48,322 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.047
2016-05-18 08:36:48,323 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:36:48,324 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:36:48,339 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting
2016-05-18 08:36:48,339 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt"]
2016-05-18 08:36:48,340 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] sink: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedTextAll/quoted/normchartrue"]
2016-05-18 08:36:48,340 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] parallel execution of steps is enabled: false
2016-05-18 08:36:48,341 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executing total steps: 1
2016-05-18 08:36:48,341 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] allocating management threads: 1
2016-05-18 08:36:48,342 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting step: (1/1) ...xtAll/quoted/normchartrue
2016-05-18 08:36:48,516 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] submitted hadoop job: job_local715808824_0002
2016-05-18 08:36:48,517 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] tracking url: http://localhost:8080/
2016-05-18 08:36:48,523 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt
2016-05-18 08:36:48,532 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:36:48,532 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:36:48,541 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B78780B5DD5B44DDBD1B56BD498BC424, ordinal: 0
2016-05-18 08:36:48,542 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt"]
2016-05-18 08:36:48,542 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedTextAll/quoted/normchartrue"]
2016-05-18 08:36:48,543 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B78780B5DD5B44DDBD1B56BD498BC424, mem on start (mb), free: 155, total: 281, max: 672
2016-05-18 08:36:48,547 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B78780B5DD5B44DDBD1B56BD498BC424, mem on close (mb), free: 155, total: 281, max: 672
2016-05-18 08:36:48,589 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedTextAll/quoted/normchartrue/_temporary
2016-05-18 08:36:48,589 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] completed in: 00:00.250
2016-05-18 08:36:48,701 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testQuotedTextAll/quoted/normchartrue
2016-05-18 08:36:48,736 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:36:48,737 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:36:48,802 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.054
2016-05-18 08:36:48,803 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:36:48,804 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:36:48,825 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting
2016-05-18 08:36:48,825 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-spec-char.txt"]
2016-05-18 08:36:48,825 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] sink: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedTextSpecCharAll/quoted/specchartrue"]
2016-05-18 08:36:48,825 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] parallel execution of steps is enabled: false
2016-05-18 08:36:48,826 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executing total steps: 1
2016-05-18 08:36:48,826 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] allocating management threads: 1
2016-05-18 08:36:48,827 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting step: (1/1) ...arAll/quoted/specchartrue
2016-05-18 08:36:49,104 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] submitted hadoop job: job_local1074477740_0003
2016-05-18 08:36:49,105 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] tracking url: http://localhost:8080/
2016-05-18 08:36:49,110 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-spec-char.txt
2016-05-18 08:36:49,117 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:36:49,117 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:36:49,129 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D43C6755F8D74AAABBBC7555DBC8F248, ordinal: 0
2016-05-18 08:36:49,129 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-spec-char.txt"]
2016-05-18 08:36:49,130 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedTextSpecCharAll/quoted/specchartrue"]
2016-05-18 08:36:49,130 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D43C6755F8D74AAABBBC7555DBC8F248, mem on start (mb), free: 209, total: 281, max: 672
2016-05-18 08:36:49,133 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D43C6755F8D74AAABBBC7555DBC8F248, mem on close (mb), free: 209, total: 281, max: 672
2016-05-18 08:36:49,151 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedTextSpecCharAll/quoted/specchartrue/_temporary
2016-05-18 08:36:49,152 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] completed in: 00:00.327
2016-05-18 08:36:49,230 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testQuotedTextSpecCharAll/quoted/specchartrue
2016-05-18 08:36:49,250 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:36:49,250 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:36:49,288 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-05-18 08:36:49,289 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:36:49,290 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:36:49,304 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting
2016-05-18 08:36:49,305 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt"]
2016-05-18 08:36:49,305 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderAll/headerall"]
2016-05-18 08:36:49,305 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] parallel execution of steps is enabled: false
2016-05-18 08:36:49,306 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executing total steps: 1
2016-05-18 08:36:49,306 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] allocating management threads: 1
2016-05-18 08:36:49,308 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting step: (1/1) ...m/testHeaderAll/headerall
2016-05-18 08:36:49,445 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] submitted hadoop job: job_local1149950347_0004
2016-05-18 08:36:49,445 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] tracking url: http://localhost:8080/
2016-05-18 08:36:49,470 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt
2016-05-18 08:36:49,476 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:36:49,476 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:36:49,483 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BAF9E8A06D704AFD813E60CFC1CEEEB8, ordinal: 0
2016-05-18 08:36:49,484 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt"]
2016-05-18 08:36:49,484 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderAll/headerall"]
2016-05-18 08:36:49,484 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BAF9E8A06D704AFD813E60CFC1CEEEB8, mem on start (mb), free: 384, total: 397, max: 672
2016-05-18 08:36:49,487 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BAF9E8A06D704AFD813E60CFC1CEEEB8, mem on close (mb), free: 384, total: 397, max: 672
2016-05-18 08:36:49,510 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderAll/headerall/_temporary
2016-05-18 08:36:49,511 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] completed in: 00:00.206
2016-05-18 08:36:49,536 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testHeaderAll/headerall
2016-05-18 08:36:49,552 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:36:49,552 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:36:49,593 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-05-18 08:36:49,595 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:36:49,595 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:36:49,608 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting
2016-05-18 08:36:49,609 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt"]
2016-05-18 08:36:49,609 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedText/quoted/normcharfalse"]
2016-05-18 08:36:49,609 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] parallel execution of steps is enabled: false
2016-05-18 08:36:49,609 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executing total steps: 1
2016-05-18 08:36:49,609 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] allocating management threads: 1
2016-05-18 08:36:49,611 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting step: (1/1) ...Text/quoted/normcharfalse
2016-05-18 08:36:49,724 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] submitted hadoop job: job_local1830496964_0005
2016-05-18 08:36:49,726 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] tracking url: http://localhost:8080/
2016-05-18 08:36:49,731 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt
2016-05-18 08:36:49,738 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:36:49,738 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:36:49,746 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A5C89AB0CC9845F28210CEADDF95CD48, ordinal: 0
2016-05-18 08:36:49,747 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt"]
2016-05-18 08:36:49,747 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedText/quoted/normcharfalse"]
2016-05-18 08:36:49,747 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A5C89AB0CC9845F28210CEADDF95CD48, mem on start (mb), free: 325, total: 397, max: 672
2016-05-18 08:36:49,750 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A5C89AB0CC9845F28210CEADDF95CD48, mem on close (mb), free: 325, total: 397, max: 672
2016-05-18 08:36:49,773 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testQuotedText/quoted/normcharfalse/_temporary
2016-05-18 08:36:49,774 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] completed in: 00:00.165
2016-05-18 08:36:49,850 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testQuotedText/quoted/normcharfalse
2016-05-18 08:36:49,975 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:36:49,975 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:36:50,013 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-05-18 08:36:50,014 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:36:50,015 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:36:50,047 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting
2016-05-18 08:36:50,047 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] source: Hfs["TextDelimited[['ip', 'client', 'user', 'date', 'request', 'code', 'bytes', 'referrer', 'agent', 'na' | String, String, String, DateType{dateFormatString='dd/MMM/yyyy:HH:mm:ss Z',canonicalType='long'}, String, int, long, String, String, String]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/apache-clean.10.txt"]
2016-05-18 08:36:50,048 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] sink: Hfs["TextDelimited[['ip', 'client', 'user', 'date', 'request', 'code', 'bytes', 'referrer', 'agent', 'na' | String, String, String, DateType{dateFormatString='dd/MMM/yyyy:HH:mm:ss Z',canonicalType='long'}, String, int, long, String, String, String]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testFieldCoercion/testFieldCoercion"]
2016-05-18 08:36:50,048 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] parallel execution of steps is enabled: false
2016-05-18 08:36:50,048 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executing total steps: 1
2016-05-18 08:36:50,049 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] allocating management threads: 1
2016-05-18 08:36:50,049 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting step: (1/1) ...oercion/testFieldCoercion
2016-05-18 08:36:50,144 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] submitted hadoop job: job_local114736021_0006
2016-05-18 08:36:50,145 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] tracking url: http://localhost:8080/
2016-05-18 08:36:50,151 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/apache-clean.10.txt
2016-05-18 08:36:50,157 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:36:50,157 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:36:50,169 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CA51D6529C984B7E91835F20F5159BA9, ordinal: 0
2016-05-18 08:36:50,176 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['ip', 'client', 'user', 'date', 'request', 'code', 'bytes', 'referrer', 'agent', 'na' | String, String, String, DateType{dateFormatString='dd/MMM/yyyy:HH:mm:ss Z',canonicalType='long'}, String, int, long, String, String, String]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/apache-clean.10.txt"]
2016-05-18 08:36:50,177 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['ip', 'client', 'user', 'date', 'request', 'code', 'bytes', 'referrer', 'agent', 'na' | String, String, String, DateType{dateFormatString='dd/MMM/yyyy:HH:mm:ss Z',canonicalType='long'}, String, int, long, String, String, String]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testFieldCoercion/testFieldCoercion"]
2016-05-18 08:36:50,177 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CA51D6529C984B7E91835F20F5159BA9, mem on start (mb), free: 247, total: 397, max: 672
2016-05-18 08:36:50,258 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CA51D6529C984B7E91835F20F5159BA9, mem on close (mb), free: 242, total: 397, max: 672
2016-05-18 08:36:50,283 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testFieldCoercion/testFieldCoercion/_temporary
2016-05-18 08:36:50,284 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] completed in: 00:00.236
2016-05-18 08:36:50,317 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testFieldCoercion/testFieldCoercion
2016-05-18 08:36:50,344 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:36:50,345 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:36:50,407 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-18 08:36:50,408 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:36:50,408 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:36:50,435 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting
2016-05-18 08:36:50,436 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-header.txt"]
2016-05-18 08:36:50,436 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] sink: MultiSinkTap[[Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall1"], Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall2"]]]
2016-05-18 08:36:50,436 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] parallel execution of steps is enabled: false
2016-05-18 08:36:50,437 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executing total steps: 1
2016-05-18 08:36:50,437 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] allocating management threads: 1
2016-05-18 08:36:50,437 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting step: (1/1) ...2B32A4997A73D089345D83527
2016-05-18 08:36:50,557 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] submitted hadoop job: job_local61107673_0007
2016-05-18 08:36:50,558 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] tracking url: http://localhost:8080/
2016-05-18 08:36:50,566 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-header.txt
2016-05-18 08:36:50,568 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:36:50,568 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:36:50,577 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EB932E963621498D9D87AC1B80851C4F, ordinal: 0
2016-05-18 08:36:50,578 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-header.txt"]
2016-05-18 08:36:50,578 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: MultiSinkTap[[Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall1"], Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall2"]]]
2016-05-18 08:36:50,578 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EB932E963621498D9D87AC1B80851C4F, mem on start (mb), free: 181, total: 397, max: 672
2016-05-18 08:36:50,580 INFO tap.MultiSinkTap (MultiSinkTap.java:<init>(80)) - opening for write: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall1"]
2016-05-18 08:36:50,583 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_local61107673_0007_m_000000_0' - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall1/_temporary/_attempt_local61107673_0007_m_000000_0
2016-05-18 08:36:50,583 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-05-18 08:36:50,588 INFO tap.MultiSinkTap (MultiSinkTap.java:<init>(80)) - opening for write: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall2"]
2016-05-18 08:36:50,590 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:setupTask(105)) - setting up task: 'attempt_local61107673_0007_m_000000_0' - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall2/_temporary/_attempt_local61107673_0007_m_000000_0
2016-05-18 08:36:50,590 INFO io.TapOutputCollector (TapOutputCollector.java:initialize(117)) - creating path: part-00000
2016-05-18 08:36:50,596 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall1/part-00000
2016-05-18 08:36:50,597 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_local61107673_0007_m_000000_0' - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall1/_temporary/_attempt_local61107673_0007_m_000000_0
2016-05-18 08:36:50,599 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_local61107673_0007_m_000000_0' to file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall1
2016-05-18 08:36:50,600 INFO io.TapOutputCollector (TapOutputCollector.java:close(150)) - closing tap collector for: /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall2/part-00000
2016-05-18 08:36:50,600 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(162)) - committing task: 'attempt_local61107673_0007_m_000000_0' - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall2/_temporary/_attempt_local61107673_0007_m_000000_0
2016-05-18 08:36:50,602 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:commitTask(179)) - saved output of task 'attempt_local61107673_0007_m_000000_0' to file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall2
2016-05-18 08:36:50,603 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EB932E963621498D9D87AC1B80851C4F, mem on close (mb), free: 177, total: 397, max: 672
2016-05-18 08:36:50,617 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] completed in: 00:00.180
2016-05-18 08:36:50,718 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall1
2016-05-18 08:36:50,718 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testHeaderFieldsAll/headerfieldsall2
2016-05-18 08:36:50,763 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:36:50,764 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:36:50,792 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-05-18 08:36:50,793 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:36:50,794 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:36:50,809 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting
2016-05-18 08:36:50,809 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt"]
2016-05-18 08:36:50,809 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeader/header"]
2016-05-18 08:36:50,810 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] parallel execution of steps is enabled: false
2016-05-18 08:36:50,810 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executing total steps: 1
2016-05-18 08:36:50,810 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] allocating management threads: 1
2016-05-18 08:36:50,812 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting step: (1/1) ...latform/testHeader/header
2016-05-18 08:36:50,918 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] submitted hadoop job: job_local407273730_0008
2016-05-18 08:36:50,918 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] tracking url: http://localhost:8080/
2016-05-18 08:36:50,923 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt
2016-05-18 08:36:50,929 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:36:50,929 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:36:50,935 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AADCAAB42B0143579906E13D903FE882, ordinal: 0
2016-05-18 08:36:50,936 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited.txt"]
2016-05-18 08:36:50,936 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeader/header"]
2016-05-18 08:36:50,936 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AADCAAB42B0143579906E13D903FE882, mem on start (mb), free: 335, total: 397, max: 672
2016-05-18 08:36:50,939 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AADCAAB42B0143579906E13D903FE882, mem on close (mb), free: 335, total: 397, max: 672
2016-05-18 08:36:50,953 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testHeader/header/_temporary
2016-05-18 08:36:50,954 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] completed in: 00:00.144
2016-05-18 08:36:50,983 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testHeader/header
2016-05-18 08:36:50,998 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:36:50,998 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:36:51,024 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-05-18 08:36:51,025 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:36:51,025 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:36:51,034 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting
2016-05-18 08:36:51,034 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-extra-field.txt"]
2016-05-18 08:36:51,034 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testStrict/strict-nondeterministic"]
2016-05-18 08:36:51,035 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] parallel execution of steps is enabled: false
2016-05-18 08:36:51,035 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] executing total steps: 1
2016-05-18 08:36:51,035 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] allocating management threads: 1
2016-05-18 08:36:51,035 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] starting step: (1/1) ...t/strict-nondeterministic
2016-05-18 08:36:51,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] submitted hadoop job: job_local464487679_0009
2016-05-18 08:36:51,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] tracking url: http://localhost:8080/
2016-05-18 08:36:51,128 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-extra-field.txt
2016-05-18 08:36:51,134 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:36:51,134 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:36:51,141 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E4177296BC8C46A3B46D758B78FE8397, ordinal: 0
2016-05-18 08:36:51,142 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-extra-field.txt"]
2016-05-18 08:36:51,142 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['first', 'second', 'third', 'fourth', 'fifth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testStrict/strict-nondeterministic"]
2016-05-18 08:36:51,142 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E4177296BC8C46A3B46D758B78FE8397, mem on start (mb), free: 275, total: 397, max: 672
2016-05-18 08:36:51,146 ERROR element.TrapHandler (TrapHandler.java:handleReThrowableException(115)) - caught Throwable, no trap available, rethrowing
cascading.tuple.TupleException: unable to read from input identifier: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-extra-field.txt
at cascading.tuple.TupleEntrySchemeIterator.hasNext(TupleEntrySchemeIterator.java:152)
at cascading.flow.stream.element.SourceStage.map(SourceStage.java:84)
at cascading.flow.stream.element.SourceStage.run(SourceStage.java:66)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:142)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:450)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:343)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: cascading.tap.TapException: did not parse correct number of values from input data, expected: 5, got: 6:,,,,7,extra-data
at cascading.scheme.util.DelimitedParser.onlyParseLine(DelimitedParser.java:404)
at cascading.scheme.util.DelimitedParser.parseLine(DelimitedParser.java:341)
at cascading.scheme.hadoop.TextDelimited.source(TextDelimited.java:1015)
at cascading.tuple.TupleEntrySchemeIterator.getNext(TupleEntrySchemeIterator.java:166)
at cascading.tuple.TupleEntrySchemeIterator.hasNext(TupleEntrySchemeIterator.java:139)
... 11 more
2016-05-18 08:36:51,152 ERROR element.SourceStage (SourceStage.java:map(118)) - caught throwable
cascading.tuple.TupleException: unable to read from input identifier: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-extra-field.txt
at cascading.tuple.TupleEntrySchemeIterator.hasNext(TupleEntrySchemeIterator.java:152)
at cascading.flow.stream.element.SourceStage.map(SourceStage.java:84)
at cascading.flow.stream.element.SourceStage.run(SourceStage.java:66)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:142)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:450)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:343)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: cascading.tap.TapException: did not parse correct number of values from input data, expected: 5, got: 6:,,,,7,extra-data
at cascading.scheme.util.DelimitedParser.onlyParseLine(DelimitedParser.java:404)
at cascading.scheme.util.DelimitedParser.parseLine(DelimitedParser.java:341)
at cascading.scheme.hadoop.TextDelimited.source(TextDelimited.java:1015)
at cascading.tuple.TupleEntrySchemeIterator.getNext(TupleEntrySchemeIterator.java:166)
at cascading.tuple.TupleEntrySchemeIterator.hasNext(TupleEntrySchemeIterator.java:139)
... 11 more
2016-05-18 08:36:51,152 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E4177296BC8C46A3B46D758B78FE8397, mem on close (mb), free: 275, total: 397, max: 672
2016-05-18 08:36:51,154 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local464487679_0009
java.lang.Exception: cascading.tuple.TupleException: unable to read from input identifier: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-extra-field.txt
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:522)
Caused by: cascading.tuple.TupleException: unable to read from input identifier: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/delimited-extra-field.txt
at cascading.tuple.TupleEntrySchemeIterator.hasNext(TupleEntrySchemeIterator.java:152)
at cascading.flow.stream.element.SourceStage.map(SourceStage.java:84)
at cascading.flow.stream.element.SourceStage.run(SourceStage.java:66)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:142)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:450)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:343)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: cascading.tap.TapException: did not parse correct number of values from input data, expected: 5, got: 6:,,,,7,extra-data
at cascading.scheme.util.DelimitedParser.onlyParseLine(DelimitedParser.java:404)
at cascading.scheme.util.DelimitedParser.parseLine(DelimitedParser.java:341)
at cascading.scheme.hadoop.TextDelimited.source(TextDelimited.java:1015)
at cascading.tuple.TupleEntrySchemeIterator.getNext(TupleEntrySchemeIterator.java:166)
at cascading.tuple.TupleEntrySchemeIterator.hasNext(TupleEntrySchemeIterator.java:139)
... 11 more
2016-05-18 08:36:51,156 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [pipe] hadoop job job_local464487679_0009 state at FAILED
2016-05-18 08:36:51,157 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [pipe] failure info: NA
2016-05-18 08:36:51,159 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [pipe] task completion events identify failed tasks
2016-05-18 08:36:51,159 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [pipe] task completion events count: 0
2016-05-18 08:36:51,160 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] stopping all jobs
2016-05-18 08:36:51,160 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] stopping: (1/1) ...t/strict-nondeterministic
2016-05-18 08:36:51,160 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] stopped all jobs
2016-05-18 08:36:51,161 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/textdelimitedplatform/testStrict/strict-nondeterministic/_temporary
2016-05-18 08:36:51,161 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipe] completed in: 00:00.127
2016-05-18 08:36:51,162 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/textdelimitedplatform/testStrict/strict-nondeterministic