Split frame : Big datasets : On 186K rows 3200 Cols split frame took 40 mins => which is too long

[exalate-issue-sync]

1. Start h2o on hadoop

2. importFiles [ "hdfs://mr-0xd6.0xdata.loc/datasets/bigdata/custmv/customer_m_com_200KRows_3.2KCols_noheaders.csv" ]

3. Parse

4. assist splitFrame, "customer_m_com_200KRows_3_2KCols_noheaders.hex"

splitFrame "customer_m_com_200KRows_3_2KCols_noheaders.hex", [0.2], ["customer_m_com_200KRows_3_2KCols_noheaders.hex_0.20","customer_m_com_200KRows_3_2KCols_noheaders.hex_0.80"]

Task bar shows Requesting /99/Rapids past 15 mins.....

View logs :

06-22 17:09:14.667 172.16.2.189:55555 1313 # Session INFO: Method: GET , URI: /3/Frames/customer_m_com_200KRows_3_2KCols_noheaders.hex/summary, route: /3/Frames/(?.*)/summary, parms: {_exclude_fields=frames/vec_ids,frames/columns/data,frames/columns/domain,frames/columns/histogram_bins,frames/columns/percentiles, column_offset=0, frame_id=customer_m_com_200KRows_3_2KCols_noheaders.hex, column_count=20}
06-22 17:09:42.547 172.16.2.189:55555 1313 # Session INFO: Method: GET , URI: /3/Frames, route: /3/Frames, parms: {}
06-22 17:09:47.198 172.16.2.189:55555 1313 # Session INFO: Method: POST , URI: /99/Rapids, route: /99/Rapids, parms: {ast=(= !7c2a00fbc5e54a1098fb65fd0c2860a3 (h2o.runif "customer_m_com_200KRows_3_2KCols_noheaders.hex" #-1))}
06-22 17:09:50.457 172.16.2.189:55555 1313 # Session INFO: Method: POST , URI: /99/Rapids, route: /99/Rapids, parms: {ast=(= !"customer_m_com_200KRows_3_2KCols_noheaders.hex_0.20" ([ %"customer_m_com_200KRows_3_2KCols_noheaders.hex" (l %7c2a00fbc5e54a1098fb65fd0c2860a3 #0.2) "null"))}
06-22 17:09:50.457 172.16.2.189:55555 1313 # Session INFO: Method: POST , URI: /99/Rapids, route: /99/Rapids, parms: {ast=(= !"customer_m_com_200KRows_3_2KCols_noheaders.hex_0.80" ([ %"customer_m_com_200KRows_3_2KCols_noheaders.hex" (G %7c2a00fbc5e54a1098fb65fd0c2860a3 #0.2) "null"))}
06-22 17:16:47.191 172.16.2.189:55555 1313 # Session INFO: Trying to load resource /flow/css/flow-lib.css via classloader sun.misc.Launcher$AppClassLoader@7c1c8c58
06-22 17:16:47.191 172.16.2.189:55555 1313 # Session INFO: Trying to load resource /flow/css/flow.css via classloader sun.misc.Launcher$AppClassLoader@7c1c8c58
06-22 17:16:47.191 172.16.2.189:55555 1313 # Session INFO: Trying to load resource /flow/custom/custom.css via classloader sun.misc.Launcher$AppClassLoader@7c1c8c58
06-22 17:16:47.236 172.16.2.189:55555 1313 # Session INFO: Trying to load resource /flow/css/bootstrap.css.map via classloader sun.misc.Launcher$AppClassLoader@7c1c8c58

[exalate-issue-sync]

Neeraja Madabhushi commented: Split frame got completed after 40 mins .........

[exalate-issue-sync]

Neeraja Madabhushi commented: Parse took : 2min 47sec with latest bleeding edge build : h2o-3.1.0.3053

[exalate-issue-sync]

Spencer Aiello commented: this has been discussed a couple of times before --

not sure if parse is an indicator here... parse is faster than lots of things in h2o, but nevertheless it's an interesting data point :)

A better strategy:
Get yourkit out and see where time is being spent
Could also just do poor-man's version with kill -3's and eye-balling it.

[exalate-issue-sync]

Neeraja Madabhushi commented: SplitFrame : 34 mins 44 secs with latest bleeding edge build : h2o-3.1.0.3053

[exalate-issue-sync]

Spencer Aiello commented: Note to dev:

an interesting experiment to try:

use the Callback-forkVecTask pattern to possibly perform the split on Vec's in parallel, then cbind the results at the end

[exalate-issue-sync]

Neeraja Madabhushi commented: With latest Shannon 23 release same dataset took 7 mins for split frame with Prithvi's gput tweak....

[exalate-issue-sync]

Neeraja Madabhushi commented: Shannon 25:

Seeing similar issue with
splitFrame "X15Mx2_2k.hex", [0.25], ["frame_0.250","frame_0.750"]

past 10 mins its still requesting /99/rapids

[exalate-issue-sync]

Neeraja Madabhushi commented: It
Error evaluating cell

Error evaluating future[1]

Error calling POST /99/Rapids with opts {"ast":"(gput "frame_0.750" ([ %"X15Mx2_2k.hex" (G %c45399db4e4f4f47bc03d48c61ed0cad #0.25) "null"))"}

Java heap space

TOGGLE STACK TRACE
Java heap space (water.exceptions.H2OIllegalArgumentException)
water.api.RapidsHandler.exec(RapidsHandler.java:132)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:606)
water.api.Handler.handle(Handler.java:56)
water.api.RequestServer.handle(RequestServer.java:676)
water.api.RequestServer.serve(RequestServer.java:613)
water.NanoHTTPD$HTTPSession.run(NanoHTTPD.java:438)
java.lang.Thread.run(Thread.java:745)

[exalate-issue-sync]

Neeraja Madabhushi commented: h2o started on hadoop as below :

hadoop jar h2odriver.jar -nodes 4 -mapperXmx 40g -output June25-1 -baseport 55555 -flow_dir hdfs:///user/neeraja/myflow-1 -disown

[exalate-issue-sync]

Neeraja Madabhushi commented: Started cluster with above hadoop command, and did below:

Steps

1. importFiles [ "hdfs://mr-0xd6.0xdata.loc/datasets/15Mx2.2k.csv" ]
2. Parse
3. getFrameSummary "X15Mx2_2k.hex"
4. assist splitFrame, "X15Mx2_2k.hex"
5. splitFrame "X15Mx2_2k.hex", [0.25], ["frame_0.250","frame_0.750"]
   Error :

Error evaluating cell

Error evaluating future[1]

Error calling POST /99/Rapids with opts {"ast":"(gput "frame_0.750" ([ %"X15Mx2_2k.hex" (G %c45399db4e4f4f47bc03d48c61ed0cad #0.25) "null"))"}

Java heap space

TOGGLE STACK TRACE
Java heap space (water.exceptions.H2OIllegalArgumentException)
water.api.RapidsHandler.exec(RapidsHandler.java:132)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:606)
water.api.Handler.handle(Handler.java:56)
water.api.RequestServer.handle(RequestServer.java:676)
water.api.RequestServer.serve(RequestServer.java:613)
water.NanoHTTPD$HTTPSession.run(NanoHTTPD.java:438)
java.lang.Thread.run(Thread.java:745)

[exalate-issue-sync]

Neeraja Madabhushi commented: Tried with shannon-25 and server crashed .....

Parse took : 11:27:886
Split frame crashed server around 30 mins or so

1. importFiles [ "hdfs://mr-0xd6.0xdata.loc/datasets/15Mx2.2k.csv" ]
2. Parse
3. getFrameSummary "X15Mx2_2k.hex"
4. assist splitFrame, "X15Mx2_2k.hex"
5. splitFrame "X15Mx2_2k.hex", [0.25], ["frame_0.250","frame_0.750"]

Flow error:

Error evaluating cell

Error evaluating future[1]

Error calling POST /99/Rapids with opts {"ast":"(gput "frame_0.750" ([ %"X15Mx2_2k.hex" (G %bc902366751d490c9ed8e94cf4437e1d #0.25) "null"))"}

TOGGLE STACK TRACE
Error
at new FlowError (http://172.16.2.181:55555/flow/js/flow.js:3468:25)
at Object. (http://172.16.2.181:55555/flow/js/flow.js:4281:528)
at fire (http://172.16.2.181:55555/flow/js/flow-lib.js:3852:30)
at Object.self.fireWith [as rejectWith] (http://172.16.2.181:55555/flow/js/flow-lib.js:3964:7)
at done (http://172.16.2.181:55555/flow/js/flow-lib.js:9019:14)
at XMLHttpRequest. (http://172.16.2.181:55555/flow/js/flow-lib.js:9352:9)

==================
Yarn logs

Link to application yarn logs

http://mr-0xd7.0xdata.loc:19888/jobhistory/job/job_1433965452861_0523/jobhistory/job/job_1433965452861_0523

http://mr-0xd7.0xdata.loc:19888/jobhistory/logs/mr-0xd2.0xdata.loc:45454/container_1433965452861_0523_01_000001/job_1433965452861_0523/neeraja/syslog/?start=0

2015-06-26 13:13:08,339 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: Diagnostics report from attempt_1433965452861_0523_m_000003_0: AttemptID:attempt_1433965452861_0523_m_000003_0 Timed out after 600 secs
2015-06-26 13:13:08,340 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1433965452861_0523_m_000003_0 TaskAttempt Transitioned from RUNNING to FAIL_CONTAINER_CLEANUP
2015-06-26 13:13:08,341 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: Processing the event EventType: CONTAINER_REMOTE_CLEANUP for container container_1433965452861_0523_01_000005 taskAttempt attempt_1433965452861_0523_m_000003_0
2015-06-26 13:13:08,342 INFO [ContainerLauncher #4] org.apache.hadoop.mapreduce.v2.app.launcher.ContainerLauncherImpl: KILLING attempt_1433965452861_0523_m_000003_0
2015-06-26 13:13:08,365 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1433965452861_0523_m_000003_0 TaskAttempt Transitioned from FAIL_CONTAINER_CLEANUP to FAIL_TASK_CLEANUP
2015-06-26 13:13:08,365 INFO [CommitterEvent Processor #1] org.apache.hadoop.mapreduce.v2.app.commit.CommitterEventHandler: Processing the event EventType: TASK_ABORT
2015-06-26 13:13:08,385 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskAttemptImpl: attempt_1433965452861_0523_m_000003_0 TaskAttempt Transitioned from FAIL_TASK_CLEANUP to FAILED
2015-06-26 13:13:08,398 INFO [AsyncDispatcher event handler] org.apache.hadoop.mapreduce.v2.app.job.impl.TaskImpl: task_1433965452861_0523_m_000003 Task Transitioned from RUNNING to FAILED
2015-06-26 13:13:08,398 INFO [Thread-51] org.apache.hadoop.mapreduce.v2.app.rm.RMContainerRequestor: 1 failures on node mr-0xd8.0xdata.loc
2015-06-26

[exalate-issue-sync]

Neeraja Madabhushi commented: Tried with Shannon 22 => Flow 18

Parse time : 7:19:696
Split frame : within 11 minutes it failed and server is down

Steps :

1. importFiles [ "hdfs://mr-0xd6.0xdata.loc/datasets/15Mx2.2k.csv" ]
2. Parse
3. getFrameSummary "X15Mx2_2k.hex"
4. assist splitFrame, "X15Mx2_2k.hex"
5. splitFrame "X15Mx2_2k.hex", [0.25], ["frame_0.250","frame_0.750"]

Error evaluating cell

Error evaluating future[1]

Error calling POST /99/Rapids with opts {"ast":"(= !"frame_0.750" ([ %"X15Mx2_2k.hex" (G %0b9e2583dc784ae8a51e1afa1b37e707 #0.25) "null"))"}

water.DException$DistributedException: from /172.16.2.183:55555; by class water.fvec.Frame$DeepSelect; class water.DException$DistributedException: from /172.16.2.188:55555; by class water.fvec.Frame$DeepSelect; class java.lang.OutOfMemoryError: Java heap space

TOGGLE STACK TRACE
water.DException$DistributedException: from /172.16.2.183:55555; by class water.fvec.Frame$DeepSelect; class water.DException$DistributedException: from /172.16.2.188:55555; by class water.fvec.Frame$DeepSelect; class java.lang.OutOfMemoryError: Java heap space (water.exceptions.H2OIllegalArgumentException)
water.api.RapidsHandler.exec(RapidsHandler.java:132)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:606)
water.api.Handler.handle(Handler.java:56)
water.api.RequestServer.handle(RequestServer.java:677)
water.api.RequestServer.serve(RequestServer.java:614)
water.NanoHTTPD$HTTPSession.run(NanoHTTPD.java:438)
java.lang.Thread.run(Thread.java:745)

[exalate-issue-sync]

Neeraja Madabhushi commented:
Tried with latest bleeding edge build on hdp2.2:

wget http://h2o-release.s3.amazonaws.com/h2o/master/3059/h2o-3.1.0.3059-hdp2.2.zip

For X15Mx2_2k.hex :

Parse took : 9:21:734
Below is error from logs : Split frame is running past 35 mins.......

06-29 12:34:57.736 172.16.2.181:55555 4768 # Session INFO: Method: GET , URI: /3/Frames, route: /3/Frames, parms: {}
06-29 12:36:20.263 172.16.2.181:55555 4768 # Session INFO: Method: POST , URI: /99/Rapids, route: /99/Rapids, parms: {ast=(gput f429b67eae244c6e9ac84cd576ba12ef (h2o.runif "X15Mx2_2k.hex" #-1))}
06-29 12:36:20.639 172.16.2.181:55555 4768 # Session INFO: Method: POST , URI: /99/Rapids, route: /99/Rapids, parms: {ast=(gput "frame_0.250" ([ %"X15Mx2_2k.hex" (l %f429b67eae244c6e9ac84cd576ba12ef #0.25) "null"))}
06-29 12:36:20.640 172.16.2.181:55555 4768 # Session INFO: Method: POST , URI: /99/Rapids, route: /99/Rapids, parms: {ast=(gput "frame_0.750" ([ %"X15Mx2_2k.hex" (G %f429b67eae244c6e9ac84cd576ba12ef #0.25) "null"))}
06-29 12:43:24.449 172.16.2.181:55555 4768 # Session ERRR: java.net.SocketException: Broken pipe
06-29 12:56:12.775 172.16.2.181:55555 4768 # Session ERRR: java.net.SocketException: Broken pipe

[exalate-issue-sync]

Neeraja Madabhushi commented: For hdfs://mr-0xd6/datasets/bigdata/custmv/customer_m_com_200k_3.2KCols.csv

Parse took : 2:34.420
Split : 4:47:85

[exalate-issue-sync]

Neeraja Madabhushi commented: 2 more runs on split frame after increasing memory 5 nodes * 60g => 300g and starting cluster as below:

hadoop jar h2odriver.jar -nodes 5 -mapperXmx 60g -output June29-1 -baseport 55555 -flow_dir hdfs:///user/neeraja/myflow-1 -disown

Parse response time : 10:43:963
Split frame with 2575 completed in 12 mins
Split frame with 2080 completed in 15 mins