Created
May 1, 2011 11:49
-
-
Save xk/950443 to your computer and use it in GitHub Desktop.
The problem has something to do with the GC.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| /* | |
| problem2.js, 20110501 jorge@jorgechamorro.com | |
| to run: $node --expose-gc problem2.js | |
| problem2.js is just like problem.js, but does a gc() whenever a BAD happens. | |
| After the gc() it runs fine again for quite while, so the problem must have something to do with the GC. | |
| ****************** | |
| problem.js, 20110417 jorge@jorgechamorro.com | |
| Demonstrates a problem in Buffer.prototype.write() with cons-strings (also known as ropes) | |
| run this as node --trace-gc problem.js | |
| and you'll see that often the buf.write() takes 50x times as long to complete (marked as '**** BAD'). | |
| After a GC cycle it returns to normal/good for a little while. | |
| If the string is passed joined `[pre,str].join('')` it works fine, always. | |
| Tested in Ubuntu and OSX. | |
| */ | |
| var str = ''; | |
| var kSize= 256*1024; | |
| var i = kSize; | |
| var flipflop = 0; | |
| while (i--) { | |
| if (flipflop = !flipflop) str= 'C' + str; | |
| else str = str + 'C'; | |
| } | |
| //str= [str, ''].join(''); // Uncomment this and the problem disappears. | |
| console.log('str.length -> ' + str.length); | |
| var ctr= 0; | |
| var maxT= -1; | |
| var pre= "Anything"; | |
| Object.prototype.padLeft= function (len) { | |
| var str= '' + this; | |
| while (str.length < len) str = " " + str; | |
| return str; | |
| }; | |
| var buf; | |
| (function loop () { | |
| buf = new Buffer(kSize); | |
| var t0= Date.now(); | |
| buf.write(pre + str); | |
| //buf.write([pre,str].join('')); // this works too. | |
| t0= Date.now() - t0; | |
| var suffix= ''; | |
| if (t0 > 100) { | |
| //if when BAD we do a gc() it returns to normal speed for quite a while. | |
| var t1= Date.now(); | |
| gc(); | |
| t1= Date.now()- t1; | |
| suffix= " ********* gc() -> "+ t1; | |
| } | |
| if (t0 > maxT) { | |
| gc(); | |
| maxT= t0; | |
| } | |
| console.log('ctr ' + (ctr++).padLeft(4) | |
| + " maxT " + (maxT).padLeft(4) | |
| + " t0 "+ (t0).padLeft(4) | |
| + (t0 < 100 ? ' good' : ' **** BAD') | |
| + suffix | |
| ); | |
| process.nextTick(loop); | |
| })(); | |
| /* | |
| Sample problem2.js output: | |
| $ node --expose_gc /Users/jorge/Desktop/problem.js | |
| str.length -> 262144 | |
| ctr 0 maxT 6 t0 6 good | |
| ctr 1 maxT 6 t0 6 good | |
| ctr 2 maxT 6 t0 6 good | |
| ctr 3 maxT 7 t0 7 good | |
| ctr 4 maxT 7 t0 6 good | |
| ctr 5 maxT 7 t0 6 good | |
| ctr 6 maxT 8 t0 8 good | |
| ctr 7 maxT 8 t0 6 good | |
| ctr 8 maxT 8 t0 6 good | |
| ctr 9 maxT 8 t0 7 good | |
| ctr 10 maxT 8 t0 7 good | |
| ctr 11 maxT 8 t0 6 good | |
| ctr 12 maxT 8 t0 7 good | |
| ctr 13 maxT 8 t0 6 good | |
| ctr 14 maxT 8 t0 6 good | |
| ctr 15 maxT 8 t0 7 good | |
| ctr 16 maxT 8 t0 6 good | |
| ctr 17 maxT 8 t0 7 good | |
| ctr 18 maxT 8 t0 7 good | |
| ctr 19 maxT 8 t0 7 good | |
| ctr 20 maxT 8 t0 6 good | |
| ctr 21 maxT 8 t0 6 good | |
| ctr 22 maxT 8 t0 7 good | |
| ctr 23 maxT 8 t0 7 good | |
| ctr 24 maxT 8 t0 6 good | |
| ctr 25 maxT 8 t0 7 good | |
| ctr 26 maxT 8 t0 7 good | |
| ctr 27 maxT 8 t0 6 good | |
| ctr 28 maxT 8 t0 7 good | |
| ctr 29 maxT 8 t0 6 good | |
| ctr 30 maxT 8 t0 7 good | |
| ctr 31 maxT 8 t0 7 good | |
| ctr 32 maxT 8 t0 7 good | |
| ctr 33 maxT 8 t0 6 good | |
| ctr 34 maxT 8 t0 7 good | |
| ctr 35 maxT 8 t0 7 good | |
| ctr 36 maxT 8 t0 6 good | |
| ctr 37 maxT 8 t0 7 good | |
| ctr 38 maxT 337 t0 337 **** BAD ********* gc() -> 16 | |
| ctr 39 maxT 337 t0 7 good | |
| ctr 40 maxT 337 t0 6 good | |
| ctr 41 maxT 337 t0 6 good | |
| ctr 42 maxT 337 t0 6 good | |
| ctr 43 maxT 337 t0 6 good | |
| ctr 44 maxT 337 t0 7 good | |
| ctr 45 maxT 337 t0 8 good | |
| ctr 46 maxT 337 t0 6 good | |
| ctr 47 maxT 337 t0 7 good | |
| ctr 48 maxT 337 t0 6 good | |
| ctr 49 maxT 337 t0 7 good | |
| ctr 50 maxT 337 t0 6 good | |
| ctr 51 maxT 337 t0 8 good | |
| ctr 52 maxT 337 t0 6 good | |
| ctr 53 maxT 337 t0 6 good | |
| ctr 54 maxT 337 t0 6 good | |
| ctr 55 maxT 337 t0 6 good | |
| ctr 56 maxT 337 t0 7 good | |
| ctr 57 maxT 337 t0 6 good | |
| ctr 58 maxT 337 t0 10 good | |
| ctr 59 maxT 337 t0 7 good | |
| ctr 60 maxT 337 t0 7 good | |
| ctr 61 maxT 337 t0 6 good | |
| ctr 62 maxT 337 t0 6 good | |
| ctr 63 maxT 337 t0 6 good | |
| ctr 64 maxT 337 t0 9 good | |
| ctr 65 maxT 337 t0 7 good | |
| ctr 66 maxT 337 t0 6 good | |
| ctr 67 maxT 337 t0 6 good | |
| ctr 68 maxT 337 t0 6 good | |
| ctr 69 maxT 337 t0 6 good | |
| ctr 70 maxT 389 t0 389 **** BAD ********* gc() -> 15 | |
| ctr 71 maxT 389 t0 7 good | |
| ctr 72 maxT 389 t0 6 good | |
| ctr 73 maxT 389 t0 6 good | |
| ctr 74 maxT 389 t0 6 good | |
| ctr 75 maxT 389 t0 6 good | |
| ctr 76 maxT 389 t0 7 good | |
| ctr 77 maxT 389 t0 7 good | |
| ctr 78 maxT 389 t0 6 good | |
| ctr 79 maxT 389 t0 6 good | |
| ctr 80 maxT 389 t0 6 good | |
| ctr 81 maxT 389 t0 6 good | |
| ctr 82 maxT 389 t0 6 good | |
| ctr 83 maxT 389 t0 8 good | |
| ctr 84 maxT 389 t0 7 good | |
| ctr 85 maxT 389 t0 6 good | |
| ctr 86 maxT 389 t0 7 good | |
| ctr 87 maxT 389 t0 6 good | |
| ctr 88 maxT 389 t0 6 good | |
| ctr 89 maxT 389 t0 7 good | |
| ctr 90 maxT 389 t0 8 good | |
| ctr 91 maxT 389 t0 6 good | |
| ctr 92 maxT 389 t0 6 good | |
| ctr 93 maxT 389 t0 6 good | |
| ctr 94 maxT 389 t0 7 good | |
| ctr 95 maxT 389 t0 6 good | |
| ctr 96 maxT 389 t0 9 good | |
| ctr 97 maxT 389 t0 6 good | |
| ctr 98 maxT 389 t0 7 good | |
| ctr 99 maxT 389 t0 6 good | |
| ctr 100 maxT 389 t0 7 good | |
| ctr 101 maxT 389 t0 6 good | |
| ctr 102 maxT 389 t0 346 **** BAD ********* gc() -> 14 | |
| ctr 103 maxT 389 t0 6 good | |
| ctr 104 maxT 389 t0 6 good | |
| ctr 105 maxT 389 t0 6 good | |
| ctr 106 maxT 389 t0 6 good | |
| ctr 107 maxT 389 t0 6 good | |
| ctr 108 maxT 389 t0 7 good | |
| ctr 109 maxT 389 t0 8 good | |
| ctr 110 maxT 389 t0 7 good | |
| etc. | |
| Sample problem.js output: | |
| $ node --trace-gc problem.js | |
| Scavenge 2.5 -> 2.2 MB, 1 ms. | |
| Mark-sweep 3.1 -> 2.8 MB, 4 ms. | |
| Scavenge 3.8 -> 3.8 MB, 1 ms. | |
| Scavenge 5.3 -> 5.3 MB, 4 ms. | |
| Scavenge 6.8 -> 6.8 MB, 3 ms. | |
| Mark-sweep 9.8 -> 9.8 MB, 21 ms. | |
| str.length -> 262144 | |
| ctr 0 maxT 6 t0 6 good | |
| ctr 1 maxT 7 t0 7 good | |
| ctr 2 maxT 7 t0 6 good | |
| ctr 3 maxT 7 t0 6 good | |
| ctr 4 maxT 7 t0 6 good | |
| ctr 5 maxT 7 t0 7 good | |
| ctr 6 maxT 332 t0 332 **** BAD | |
| ctr 7 maxT 332 t0 332 **** BAD | |
| ctr 8 maxT 332 t0 332 **** BAD | |
| ctr 9 maxT 332 t0 332 **** BAD | |
| ctr 10 maxT 333 t0 333 **** BAD | |
| ctr 11 maxT 356 t0 356 **** BAD | |
| ctr 12 maxT 356 t0 347 **** BAD | |
| ctr 13 maxT 356 t0 336 **** BAD | |
| ctr 14 maxT 356 t0 332 **** BAD | |
| ctr 15 maxT 356 t0 330 **** BAD | |
| ctr 16 maxT 356 t0 331 **** BAD | |
| ctr 17 maxT 356 t0 332 **** BAD | |
| ctr 18 maxT 356 t0 331 **** BAD | |
| ctr 19 maxT 356 t0 332 **** BAD | |
| ctr 20 maxT 356 t0 333 **** BAD | |
| ctr 21 maxT 356 t0 331 **** BAD | |
| ctr 22 maxT 356 t0 333 **** BAD | |
| ctr 23 maxT 356 t0 332 **** BAD | |
| ctr 24 maxT 356 t0 330 **** BAD | |
| ctr 25 maxT 356 t0 332 **** BAD | |
| ctr 26 maxT 356 t0 348 **** BAD | |
| ctr 27 maxT 356 t0 334 **** BAD | |
| ctr 28 maxT 356 t0 334 **** BAD | |
| ctr 29 maxT 356 t0 332 **** BAD | |
| ctr 30 maxT 356 t0 330 **** BAD | |
| ctr 31 maxT 356 t0 332 **** BAD | |
| ctr 32 maxT 356 t0 333 **** BAD | |
| ctr 33 maxT 356 t0 331 **** BAD | |
| ctr 34 maxT 356 t0 332 **** BAD | |
| ctr 35 maxT 356 t0 332 **** BAD | |
| ctr 36 maxT 356 t0 332 **** BAD | |
| ctr 37 maxT 356 t0 332 **** BAD | |
| ctr 38 maxT 356 t0 334 **** BAD | |
| ctr 39 maxT 356 t0 330 **** BAD | |
| ctr 40 maxT 356 t0 333 **** BAD | |
| Scavenge 13.9 -> 12.3 MB, 2 ms. | |
| ctr 41 maxT 356 t0 345 **** BAD | |
| ctr 42 maxT 356 t0 6 good | |
| ctr 43 maxT 356 t0 6 good | |
| ctr 44 maxT 356 t0 6 good | |
| ctr 45 maxT 356 t0 7 good | |
| ctr 46 maxT 356 t0 6 good | |
| ctr 47 maxT 356 t0 7 good | |
| ctr 48 maxT 356 t0 7 good | |
| ctr 49 maxT 356 t0 6 good | |
| ctr 50 maxT 356 t0 6 good | |
| ctr 51 maxT 356 t0 6 good | |
| ctr 52 maxT 356 t0 6 good | |
| ctr 53 maxT 356 t0 6 good | |
| ctr 54 maxT 356 t0 8 good | |
| ctr 55 maxT 356 t0 7 good | |
| ctr 56 maxT 356 t0 7 good | |
| ctr 57 maxT 356 t0 6 good | |
| ctr 58 maxT 356 t0 6 good | |
| ctr 59 maxT 356 t0 6 good | |
| ctr 60 maxT 356 t0 7 good | |
| ctr 61 maxT 356 t0 6 good | |
| ctr 62 maxT 356 t0 6 good | |
| ctr 63 maxT 356 t0 7 good | |
| ctr 64 maxT 356 t0 6 good | |
| ctr 65 maxT 356 t0 335 **** BAD | |
| ctr 66 maxT 356 t0 334 **** BAD | |
| ctr 67 maxT 356 t0 332 **** BAD | |
| ctr 68 maxT 356 t0 330 **** BAD | |
| ctr 69 maxT 356 t0 332 **** BAD | |
| */ |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment