2016-01-14 23:39:00,415 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 23:39:00,431 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.flow.AssemblyPlannerPlatformTest, with platform: hadoop
2016-01-14 23:39:00,454 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-01-14 23:39:00,710 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 23:39:00,816 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:39:00,819 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 23:39:00,951 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 9C9E158F7E1F4719B357A5E93118C56D
2016-01-14 23:39:01,145 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.138
2016-01-14 23:39:01,149 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 23:39:01,149 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 23:39:01,318 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 23:39:01,320 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting
2016-01-14 23:39:01,320 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2016-01-14 23:39:01,321 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/assemblyplannerplatform/testCompositeAssembly/composite"]
2016-01-14 23:39:01,321 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] parallel execution of steps is enabled: false
2016-01-14 23:39:01,321 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executing total steps: 1
2016-01-14 23:39:01,322 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] allocating management threads: 1
2016-01-14 23:39:01,323 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting step: (1/1) ...mpositeAssembly/composite
2016-01-14 23:39:01,359 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-01-14 23:39:01,410 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-01-14 23:39:01,624 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] submitted hadoop job: job_local1028880802_0001
2016-01-14 23:39:01,625 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] tracking url: http://localhost:8080/
2016-01-14 23:39:01,716 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/apache.10.txt
2016-01-14 23:39:01,862 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:39:01,862 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:39:01,876 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C378AC59D8C74B07AF593CF7602EC6C7, ordinal: 0
2016-01-14 23:39:01,927 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2016-01-14 23:39:01,927 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'ip']]
2016-01-14 23:39:01,928 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C378AC59D8C74B07AF593CF7602EC6C7, mem on start (mb), free: 83, total: 223, max: 672
2016-01-14 23:39:01,941 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C378AC59D8C74B07AF593CF7602EC6C7, mem on close (mb), free: 83, total: 223, max: 672
2016-01-14 23:39:01,975 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 23:39:01,975 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 23:39:01,987 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D5C4A9F959AE44EEA1A10177BCC204D4, ordinal: 1
2016-01-14 23:39:01,991 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'ip']]
2016-01-14 23:39:01,991 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/assemblyplannerplatform/testCompositeAssembly/composite"]
2016-01-14 23:39:01,992 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D5C4A9F959AE44EEA1A10177BCC204D4, mem on start (mb), free: 81, total: 223, max: 672
2016-01-14 23:39:02,007 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D5C4A9F959AE44EEA1A10177BCC204D4, mem on close (mb), free: 80, total: 223, max: 672
2016-01-14 23:39:02,024 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/assemblyplannerplatform/testCompositeAssembly/composite/_temporary
2016-01-14 23:39:02,026 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] completed in: 00:00.703
2016-01-14 23:39:02,046 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output//hadoop/assemblyplannerplatform/testCompositeAssembly/composite
2016-01-14 23:39:02,066 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:39:02,067 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 23:39:02,144 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.069
2016-01-14 23:39:02,146 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 23:39:02,146 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 23:39:02,168 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting
2016-01-14 23:39:02,169 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2016-01-14 23:39:02,169 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/assemblyplannerplatform/testSimpleAssembly/simple"]
2016-01-14 23:39:02,169 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] parallel execution of steps is enabled: false
2016-01-14 23:39:02,170 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executing total steps: 1
2016-01-14 23:39:02,170 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] allocating management threads: 1
2016-01-14 23:39:02,171 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting step: (1/1) ...testSimpleAssembly/simple
2016-01-14 23:39:02,259 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] submitted hadoop job: job_local701433514_0002
2016-01-14 23:39:02,259 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] tracking url: http://localhost:8080/
2016-01-14 23:39:02,264 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/apache.10.txt
2016-01-14 23:39:02,368 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:39:02,369 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:39:02,378 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B5A6074088504EB89731CF288BE23374, ordinal: 0
2016-01-14 23:39:02,379 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2016-01-14 23:39:02,380 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'ip']]
2016-01-14 23:39:02,380 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5A6074088504EB89731CF288BE23374, mem on start (mb), free: 63, total: 318, max: 672
2016-01-14 23:39:02,382 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5A6074088504EB89731CF288BE23374, mem on close (mb), free: 63, total: 318, max: 672
2016-01-14 23:39:02,394 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 23:39:02,394 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 23:39:02,405 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F9B66492D0CC45BCB480BA1D356871F2, ordinal: 1
2016-01-14 23:39:02,406 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'ip']]
2016-01-14 23:39:02,406 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/assemblyplannerplatform/testSimpleAssembly/simple"]
2016-01-14 23:39:02,406 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F9B66492D0CC45BCB480BA1D356871F2, mem on start (mb), free: 61, total: 318, max: 672
2016-01-14 23:39:02,412 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F9B66492D0CC45BCB480BA1D356871F2, mem on close (mb), free: 61, total: 318, max: 672
2016-01-14 23:39:02,423 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/assemblyplannerplatform/testSimpleAssembly/simple/_temporary
2016-01-14 23:39:02,424 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] completed in: 00:00.255
2016-01-14 23:39:02,467 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output//hadoop/assemblyplannerplatform/testSimpleAssembly/simple