2016-05-18 01:59:39,688 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 01:59:39,705 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.flow.AssemblyPlannerPlatformTest, with platform: hadoop
2016-05-18 01:59:39,727 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-18 01:59:39,946 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 01:59:40,026 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:59:40,028 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:59:40,128 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 37FE15CE7CCE4245AACC53D06474CAC7
2016-05-18 01:59:40,311 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.126
2016-05-18 01:59:40,315 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:59:40,316 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:59:40,510 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 01:59:40,512 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] starting
2016-05-18 01:59:40,512 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:59:40,513 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/assemblyplannerplatform/testCompositeAssembly/composite"]
2016-05-18 01:59:40,513 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] parallel execution of steps is enabled: false
2016-05-18 01:59:40,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] executing total steps: 1
2016-05-18 01:59:40,515 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] allocating management threads: 1
2016-05-18 01:59:40,516 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] starting step: (1/1) ...mpositeAssembly/composite
2016-05-18 01:59:40,550 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 01:59:40,584 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 01:59:40,765 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] submitted hadoop job: job_local_0001
2016-05-18 01:59:40,766 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] tracking url: http://localhost:8080/
2016-05-18 01:59:40,838 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt
2016-05-18 01:59:40,993 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:59:40,994 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:59:41,007 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D6EA75F55BDE41A487D0093C7898ED37, ordinal: 0
2016-05-18 01:59:41,045 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:59:41,045 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'ip']]
2016-05-18 01:59:41,046 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6EA75F55BDE41A487D0093C7898ED37, mem on start (mb), free: 86, total: 223, max: 672
2016-05-18 01:59:41,057 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6EA75F55BDE41A487D0093C7898ED37, mem on close (mb), free: 85, total: 223, max: 672
2016-05-18 01:59:43,830 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:59:43,830 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:59:43,849 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: CF50C1C954CE468E8E86D296542C1D6A, ordinal: 1
2016-05-18 01:59:43,853 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'ip']]
2016-05-18 01:59:43,853 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/assemblyplannerplatform/testCompositeAssembly/composite"]
2016-05-18 01:59:43,853 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CF50C1C954CE468E8E86D296542C1D6A, mem on start (mb), free: 84, total: 223, max: 672
2016-05-18 01:59:43,872 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CF50C1C954CE468E8E86D296542C1D6A, mem on close (mb), free: 83, total: 223, max: 672
2016-05-18 01:59:46,833 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/assemblyplannerplatform/testCompositeAssembly/composite/_temporary
2016-05-18 01:59:46,834 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] completed in: 00:06.319
2016-05-18 01:59:46,859 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/assemblyplannerplatform/testCompositeAssembly/composite
2016-05-18 01:59:46,879 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:59:46,880 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:59:46,998 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.104
2016-05-18 01:59:47,001 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:59:47,001 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:59:47,031 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] starting
2016-05-18 01:59:47,031 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:59:47,032 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/assemblyplannerplatform/testSimpleAssembly/simple"]
2016-05-18 01:59:47,034 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] parallel execution of steps is enabled: false
2016-05-18 01:59:47,034 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] executing total steps: 1
2016-05-18 01:59:47,034 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] allocating management threads: 1
2016-05-18 01:59:47,036 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] starting step: (1/1) ...testSimpleAssembly/simple
2016-05-18 01:59:47,121 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] submitted hadoop job: job_local_0002
2016-05-18 01:59:47,122 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] tracking url: http://localhost:8080/
2016-05-18 01:59:47,126 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt
2016-05-18 01:59:47,226 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:59:47,226 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:59:47,236 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DF74B4D1D5A4488CAC95E08D3E6032D7, ordinal: 0
2016-05-18 01:59:47,237 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:59:47,237 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'ip']]
2016-05-18 01:59:47,238 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF74B4D1D5A4488CAC95E08D3E6032D7, mem on start (mb), free: 68, total: 318, max: 672
2016-05-18 01:59:47,242 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF74B4D1D5A4488CAC95E08D3E6032D7, mem on close (mb), free: 68, total: 318, max: 672
2016-05-18 01:59:50,131 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:59:50,132 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:59:50,147 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D8087AB869884C5CAE5DD9ACB631E316, ordinal: 1
2016-05-18 01:59:50,148 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'ip']]
2016-05-18 01:59:50,149 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/assemblyplannerplatform/testSimpleAssembly/simple"]
2016-05-18 01:59:50,149 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D8087AB869884C5CAE5DD9ACB631E316, mem on start (mb), free: 67, total: 318, max: 672
2016-05-18 01:59:50,155 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D8087AB869884C5CAE5DD9ACB631E316, mem on close (mb), free: 66, total: 318, max: 672
2016-05-18 01:59:53,135 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/assemblyplannerplatform/testSimpleAssembly/simple/_temporary
2016-05-18 01:59:53,136 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [] completed in: 00:06.103
2016-05-18 01:59:53,152 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/assemblyplannerplatform/testSimpleAssembly/simple