I created this script for profiling use:
var fs = require("fs");
var rh = require("./reversehuffman");
var textutils = require("./textutils");
let source = fs.readFileSync("../doc/independence.txt", {encoding: "utf-8", flag: "r"});
let ft = textutils.frequencyTable(4, source);
for(let i = 0; i < 1000; i++) {
rh.encrypt("this is some plain text", ft);
}
Running my initial implementation through the profiler, I get the following report (report cropped):
Statistical profiling result from /home/starr/svn/plainsight-addon/lib/v8.log, (77854 ticks, 0 unaccounted, 0 excluded).
[Shared libraries]:
ticks total nonlib name
31451 40.4% 0.0% /usr/lib/libv8.so.3.14.5
36 0.0% 0.0% /lib/x86_64-linux-gnu/libc-2.17.so
16 0.0% 0.0% 7fff2d9fe000-7fff2da00000
3 0.0% 0.0% /usr/bin/nodejs
1 0.0% 0.0% /lib/x86_64-linux-gnu/libpthread-2.17.so
1 0.0% 0.0% /lib/x86_64-linux-gnu/libm-2.17.so
[JavaScript]:
ticks total nonlib name
21179 27.2% 45.7% LazyCompile: encrypt /home/starr/svn/plainsight-addon/lib/reversehuffman.js:60
8920 11.5% 19.2% LazyCompile: *indexOf native string.js:118
5013 6.4% 10.8% Stub: KeyedLoadElementStub
3718 4.8% 8.0% Stub: CEntryStub
395 0.5% 0.9% KeyedLoadIC: args_count: 0
177 0.2% 0.4% LazyCompile: huffmantree /home/starr/svn/plainsight-addon/lib/textutils.js:219
128 0.2% 0.3% Stub: FastNewClosureStub
85 0.1% 0.2% LazyCompile: *sort native array.js:741
79 0.1% 0.2% LazyCompile: *slice native string.js:510
78 0.1% 0.2% LazyCompile: *InsertionSort native array.js:764
60 0.1% 0.1% Builtin: A builtin from the snapshot
58 0.1% 0.1% Stub: FastCloneShallowObjectStub
54 0.1% 0.1% LazyCompile: *self.push /home/starr/svn/plainsight-addon/lib/priority_queue.js:129
52 0.1% 0.1% LazyCompile: *QuickSort native array.js:793
51 0.1% 0.1% LazyCompile: huffmanencodetoken /home/starr/svn/plainsight-addon/lib/textutils.js:179
Within the table, the 'ticks' represents the number of times the sampling profiler detected that the code was within that function. Overall, the baseline test takes 1 minute, 21.828 seconds of user time.
(By impact, I should focus on encrypt first, but I'll go after indexOf first because the costs to improve are much smaller.)
A surprising amount of time is spent in indexOf, within the encryption algorithm, we are scanning the key value and extracting strings that start with a prefix. Mozilla provides a String.startsWith function, but it is implemented in terms of computing indexOf and comparing against zero.
As an alternative, I implement a beginsWith alternate function:
if (!String.prototype.beginsWith) {
Object.defineProperty(String.prototype, 'beginsWith', {
enumerable: false,
configurable: false,
writable: false,
value: function (prefix) {
"use strict";
if(this.length < prefix.length) {
return false;
} else {
for(let i = 0; i < prefix.length; i++) {
if(this.charAt(i) != prefix.charAt(i)) {
return false;
}
}
return true;
}
}
});
}
Re-running the tests, I get:
| Implementation | User Time |
|---|---|
| (Baseline) String.indexOf(...) === 0 | 1m21.828s |
| String.beginsWith(...) | 1m10.723s |
That shows a nice gross improvement, but what do the more detailed results say?
Statistical profiling result from /home/starr/svn/plainsight-addon/lib/v8.log, (65316 ticks, 0 unaccounted, 0 excluded).
[Shared libraries]:
ticks total nonlib name
2253 3.4% 0.0% /usr/lib/libv8.so.3.14.5
524 0.8% 0.0% /lib/x86_64-linux-gnu/libc-2.17.so
57 0.1% 0.0% 7ffff93fe000-7ffff9400000
2 0.0% 0.0% /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.18
1 0.0% 0.0% /lib/x86_64-linux-gnu/libm-2.17.so
[JavaScript]:
ticks total nonlib name
28448 43.6% 45.5% LazyCompile: Object.defineProperty.value /home/starr/svn/plainsight-addon/lib/reversehuffman.js:22
18774 28.7% 30.0% LazyCompile: encrypt /home/starr/svn/plainsight-addon/lib/reversehuffman.js:81
4278 6.5% 6.8% Stub: KeyedLoadElementStub
3993 6.1% 6.4% Stub: FastNewBlockContextStub
3549 5.4% 5.7% Stub: CompareICStub {1}
774 1.2% 1.2% Stub: CompareICStub {2}
398 0.6% 0.6% Stub: ToBooleanStub_Bool
390 0.6% 0.6% KeyedLoadIC: args_count: 0
142 0.2% 0.2% LazyCompile: huffmantree /home/starr/svn/plainsight-addon/lib/textutils.js:219
137 0.2% 0.2% Stub: FastNewClosureStub
93 0.1% 0.1% LazyCompile: *InsertionSort native array.js:764
90 0.1% 0.1% LazyCompile: *sort native array.js:741
82 0.1% 0.1% LazyCompile: *slice native string.js:510
The Object.defineProperty.value refers to the new beginsWith code. Why is that so expensive? To see if it is a one-time expense versus a high overhead, I incremented the iterations from 1000 to 10000 in my profiling script and re-ran. That run took 11m43.463s of user time (703.463 seconds), which is almost exactly ten times the previous amount of time. The detailed profiler results showed the same -- the number of ticks is scaling with the number of iterations, so it is not a setup expense.
Furthermore, making the function stand-alone is not helpful (although it does make the detailed results easier to understand since the actual function being executed isn't hiding behind Object.defineProperty.value):
| Implementation | User Time |
|---|---|
| (Baseline) String.indexOf(...) === 0 | 1m21.828s |
| String.beginsWith(...) | 1m10.723s |
| beginsWith(str, prefix) | 1m11.457s |
So, at this point, we've made a slight improvement in performance but we need to now work on the main algorithm rather than improving a subsidiary function.
No comments:
Post a Comment