optimizations from profiling build_hyracks #68

jakebiesinger · 2013-11-21T02:07:41Z

@anbangx @Nan-Zhang @JavierJia @Elmira88

Some simple changes to our code after looking at the profiles of BUILD_HYRACKS. the enum.values() function was apparently still doing a lot of work (or was being called so many times as to make it seem that way). I swapped it with a static final array of the same name.

6f40f96 will cause more GC overhead but it's negligible compared to the deepcopy cost. I'm running timings now and will update this when I have them.

A few other items I noticed:

50% of the time is in writing but 1/2 of that time is actually spent in *.getSerializedLength()! We may want to cache the length or something!
iterating over the treesets takes a looong time. TreeSet iterators are by far our most costly operation.

JavierJia · 2013-11-21T05:33:55Z

genomix/genomix-data/src/main/java/edu/uci/ics/genomix/minicluster/GenerateGraphViz.java

@@ -148,7 +148,7 @@ public static void writeHDFSBinToHDFSSvg(JobConf conf, String srcDir, String des

    public static String convertEdgeToGraph(String outputNode, Node value, GRAPH_TYPE graphType) {
        String outputEdge = "";
-        for (EDGETYPE et : EDGETYPE.values()) {
+        for (EDGETYPE et : EDGETYPE.values) {


Could you explain the different between the values() and value ?

values() is a function that's automatically generated for all enum types and which returns a static final array including all the enum values (so FF, FR, RF and RR in this case). values as I've added here is shadowing that generated function with a public static final enum[]. I'm essentially bypassing the getter for this enum type, which was taking up to 5% of the total runtime.

I can rename away from .values so it's not so ambiguous. In fact, it's weird that java lets me have a field called values when I can also call the function values().

JavierJia · 2013-11-21T05:41:12Z

About this

50% of the time is in writing but 1/2 of that time is actually spent in *.getSerializedLength()! We may want to cache the length or something!

I suggest we remove this method, because every time we serialized node, we call this

public byte[] marshalToByteArray() throws IOException {
        ByteArrayOutputStream baos = new ByteArrayOutputStream(getSerializedLength());
        DataOutputStream out = new DataOutputStream(baos);
        write(out);
        return baos.toByteArray();
    }

When the caller want to know the length, just let it to get the length of the returned byte[].

JavierJia · 2013-11-21T05:57:58Z

About the iterator issues, the TreeSet.iterator is really complicated. By now , we didn't use some range query operations, maybe we can just change it to HashSet ?

jakebiesinger · 2013-11-21T18:44:39Z

When the caller want to know the length, just let it to get the length of the returned byte[].

Good point. I had thought that this code was called directly by pregelix/hyracks. Turns out that we control the caller in this case so we can do it. Looking at the API for ByteArrayOutputStream, I see that it wil handle growing if it needs to as well. So we truly don't need this funciton. Good catch.

jakebiesinger · 2013-11-21T18:45:53Z

About the iterator issues, the TreeSet.iterator is really complicated. By now , we didn't use some range query operations, maybe we can just change it to HashSet

Yeah, that's an easy fix. The only thing we lose is a syntactically clear way to get the (one and) only element in the set.

jakebiesinger · 2013-11-21T20:10:54Z

Total graph build time with one thread goes from 26.5 to 23 minutes, so about 10% savings.

JavierJia · 2013-11-21T20:20:02Z

this 10% saving is decreased by this branch ? or iterator() ? or getlength?

jakebiesinger · 2013-11-21T20:20:18Z

When the caller want to know the length, just let it to get the length of the returned byte[].

Good point. I had thought that this code was called directly by pregelix/hyracks. Turns out that we control the caller in this case so we can do it. Looking at the API for ByteArrayOutputStream, I see that it wil handle growing if it needs to as well. So we truly don't need this funciton. Good catch.

We still have to call the EdgeMap.getLenghtInBytes() on any copy operation. I could try caching the value and marking it dirty when there's an update. Or maybe we stop caring at this point.

jakebiesinger · 2013-11-21T20:21:03Z

this 10% saving is decreased by this branch ? or iterator() ? or getlength?

10% saving just from the changes committed so far. I'm working on the other changes now and will post timings once they're ready.

JavierJia · 2013-11-21T20:22:16Z

OK, I got it.

jakebiesinger · 2013-11-21T20:25:29Z

@anbangx don't close the pull request, please :D

anbangx · 2013-11-21T20:28:47Z

😄

…opy ops

jakebiesinger · 2013-11-21T20:56:40Z

Looks like 10% savings before was a fluke run. After running several times on the previous code, I see 5% on average. I've now pushed a fix for getLengths() and will do some timings and will switch over to HashSets instead of TreeSets.

Nan-Zhang · 2013-11-22T19:23:05Z

can we write a our own parsing function instead of using regex?, and can
consider the 'N'

On Thu, Nov 21, 2013 at 12:56 PM, Jake Biesinger
[email protected]:

Looks like 10% savings before was a fluke run. After running several times
on the previous code, I see 5% on average. I've now pushed a fix for
getLengths() and will do some timings and will switch over to HashSets
instead of TreeSets.

—
Reply to this email directly or view it on GitHubhttps://github.com//pull/68#issuecomment-29023631
.

jakebiesinger · 2013-11-22T19:25:45Z

can we write a our own parsing function instead of using regex?, and can
consider the 'N'

Yes... but why? You think it will be faster than the regex? Or you mean you want to special-case the N character as I mentioned in #69?

…rrelation

jakebiesinger · 2013-11-22T21:16:10Z

Okay guys, I think I'm done optimizing/profiling for a while. I'll do some timings on all these changes later but from my profiling, the remaining overhead is hyracks/pregelix code.

Timing tables for BUILD:

Ordered by Own Time:

Ordered by Total Time:

Timing tables for MERGE:

Ordered by Own Time:

Ordered by Total Time:

jakebiesinger · 2013-11-23T23:54:27Z

Timings are in:
genomix/fullstack_genomix - BUILD,HYRACKS - 38.47 min
wbiesing/optimizations-from-profiling-BUILD_HYRACKS - BUILD,HYRACKS - 33.10665 minutes

so 16% faster. Not huge but a decent speedup :) Any comments? Shall I merge it in?

JavierJia · 2013-11-24T03:06:46Z

Great. LGTM. :+1

Best Regards.

Jianfeng Jia
PhD student of Computer Science
University of California, Irvine

On Nov 23, 2013, at 3:54 PM, Jake Biesinger [email protected] wrote:

Timings are in:
genomix/fullstack_genomix - BUILD,HYRACKS - 38.47 min
wbiesing/optimizations-from-profiling-BUILD_HYRACKS - BUILD,HYRACKS - 33.10665 minutes

so 16% faster. Not huge but a decent speedup :) Any comments? Shall I merge it in?

—
Reply to this email directly or view it on GitHub.

…wbiesing/optimizations-from-profiling-BUILD_HYRACKS Conflicts: genomix/genomix- pregelix/src/main/java/edu/uci/ics/genomix/pregelix/io/VertexValueWritable.java genomix/genomix- pregelix/src/main/java/edu/uci/ics/genomix/pregelix/operator/DeBruijnGraphCleanVertex.java

…iling-BUILD_HYRACKS optimizations from profiling build_hyracks

jakebiesinger added 3 commits November 20, 2013 16:39

BUILD-profile optimize: use static final EDGETYPE.values not values()

74d3449

BUILD-profile optimize: only compile regex once

cbfaed0

BUILD-profile optimize: copy reference rather than deep copy in build

6f40f96

JavierJia reviewed Nov 21, 2013
View reviewed changes

anbangx closed this Nov 21, 2013

jakebiesinger reopened this Nov 21, 2013

jakebiesinger added 2 commits November 21, 2013 12:52

reformat

d7025f3

BUILD-profile optimize: remove getLengths() and return offsets from c…

ea862b4

…opy ops

jakebiesinger added 2 commits November 21, 2013 17:51

MERGE-profile optimize: in/out formats use tmp references

b6e4742

MERGE-profile optimize: less reading from conf; use global debug vals

f09b83a

MERGE-profile optimize: random uses hash, not many calls, to break co…

71c5bc9

…rrelation

jakebiesinger added 2 commits November 24, 2013 00:07

MERGE-profile optimize: don't send unnecessary edges in MERGE

878a6b0

MERGE-profile optimize: only send non-overlapping parts of kmers

56e3b9b

jakebiesinger added 3 commits November 25, 2013 15:04

fix coverage bug form short kmers in MERGE messages

3c0a130

fix bug in coverage; simplify merging with truncated kmers in messages

f3fb261

jakebiesinger added a commit that referenced this pull request Dec 3, 2013

Merge pull request #68 from uci-cbcl/wbiesing/optimizations-from-prof…

587d70b

…iling-BUILD_HYRACKS optimizations from profiling build_hyracks

jakebiesinger merged commit 587d70b into genomix/fullstack_genomix Dec 3, 2013

jakebiesinger deleted the wbiesing/optimizations-from-profiling-BUILD_HYRACKS branch December 3, 2013 19:30

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

optimizations from profiling build_hyracks #68

optimizations from profiling build_hyracks #68

jakebiesinger commented Nov 21, 2013

JavierJia Nov 21, 2013

jakebiesinger Nov 21, 2013

jakebiesinger Nov 21, 2013

JavierJia commented Nov 21, 2013

JavierJia commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

JavierJia commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

JavierJia commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

anbangx commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

Nan-Zhang commented Nov 22, 2013

jakebiesinger commented Nov 22, 2013

jakebiesinger commented Nov 22, 2013

jakebiesinger commented Nov 23, 2013

JavierJia commented Nov 24, 2013

optimizations from profiling build_hyracks #68

optimizations from profiling build_hyracks #68

Conversation

jakebiesinger commented Nov 21, 2013

JavierJia Nov 21, 2013

Choose a reason for hiding this comment

jakebiesinger Nov 21, 2013

Choose a reason for hiding this comment

jakebiesinger Nov 21, 2013

Choose a reason for hiding this comment

JavierJia commented Nov 21, 2013

JavierJia commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

JavierJia commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

JavierJia commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

anbangx commented Nov 21, 2013

jakebiesinger commented Nov 21, 2013

Nan-Zhang commented Nov 22, 2013

jakebiesinger commented Nov 22, 2013

jakebiesinger commented Nov 22, 2013

Timing tables for BUILD:

Ordered by Own Time:

Ordered by Total Time:

Timing tables for MERGE:

Ordered by Own Time:

Ordered by Total Time:

jakebiesinger commented Nov 23, 2013

JavierJia commented Nov 24, 2013