performance nosedives on large writes to OutputStream

[DartBot]

This issue was originally filed by dcarlson@google.com

---

Large List<int> values cause performance of SocketOutputStream.writeFrom() (and similar) to degrade dramatically. Specific timings are largely platform-dependent, but the overall effect is reproducible across machines/OSes.

The problem can be reproduced with the following code:
<code>
final int LO = 430000;
final int HI = 500000;
final int SIZE = 500000;

final int INC = 1024;

void main() {
  List<int> content = new List();
  content.insertRange(0, SIZE, 0);
  int j = 0;
  for(int i = 0; i < SIZE; i++) {
    content[i] = j;
    j++;
    if(j >= 256) j = 0;
  }
  stderr.write("size\ttime(micros)\ttime/byte\n".charCodes());
  
  for (int i = LO; i < HI; i += INC) {
    Stopwatch s = new Stopwatch();
    s.start();
    stdout.writeFrom(content, 0, i);
    s.stop();
    int time = s.elapsedInUs();
    num time_per_byte = time / i;
    stderr.write("$i\t$time\t$time_per_byte\n".charCodes());
  }
}

</code>

Run this redirecting stdout to /dev/null and it will report performance on stderr. Your exact point of failure may vary, but with the timing output, you can refine the test to demonstrate super-linear performance beyond some threshold.

For example, here is the interesting subset of output where INC is set to 16 (note this is running on Linux using dart HEAD of bleeding_edge as of 12/12/2011):
...
size micro- microsecs/
(bytes) secs byte
461376 322392 0.698762
461392 322330 0.698603
461408 322551 0.699058
461424 322620 0.699183
461440 322526 0.698955
461456 322786 0.699495
461472 322473 0.698792
461488 322711 0.699284
461504 321257 0.696109
461520 840764 1.821728
461536 2511238 5.441045
461552 4184249 9.065607
461568 5856430 12.68812
461584 7523204 16.298667
461600 9197491 19.92524
461616 10865756 23.538517
461632 12543308 27.171661
461648 14214076 30.789857
461664 15890033 34.419043
461680 17560101 38.035221

[DartBot]

This comment was originally written by dcarlson@google.com

---

For clarity, this behavior is being seen in the runtime.

[DartBot]

This comment was originally written by dcarlson@google.com

---

Also -- this performance is observed when the input to the writeFrom method is a GrowableArray.

[whesse]

This may be a GC (garbage collector) issue, and/or we may be creating a large number of objects for some reason. We will look into this.

---

Set owner to @whesse.

[floitschG]

Removed Area-Library label.
Added Area-IO label.

[sgjesse]

With lib IO v2 the test can be rewritten like this:

final int LO = 100000;
final int HI = 5000000;
final int SIZE = 5000000;

final int INC = 100000;

void main() {
  List<int> content = new List(SIZE);
  //content.insertRange(0, SIZE, 0);
  int j = 0;
  for (int i = 0; i < SIZE; i++) {
    content[i] = j;
    j++;
    if (j >= 256) j = 0;
  }
  stderr.addString("size\ttime(micros)\ttime/byte\n");

  x(int size) {
    Stopwatch s = new Stopwatch();
    s.start();
    var controller = new StreamController();
    Future done = stdout.addStream(controller.stream);
    controller.add(content.getRange(0, size));
    controller.close();
    done.then((_) {
      s.stop();
      int time = s.elapsedMicroseconds;
      num time_per_byte = time / size;
      stderr.addString("$size\t$time\t$time_per_byte\n");
      if (size < HI) x(size + INC);
    });
  }
  x(LO);
}

Running the keeps a pretty steady rate for all sizes.

---

Added Fixed label.

[kevmoo]

Removed Area-IO label.
Added Area-Library, Library-IO labels.