[erlang-bugs] out of memory and crash when using linebuf io

[Fredrik Svahn]

Hi,

I knew that the new regexp library ("re") in Erlang/OTP R12B-3 is
fast. But I wanted to know just how fast "erlgrep" could be compared
to the well-known unix grep which has been around since 1973. My input
file was quite big (about 980 Mb) and in the first attempt it took
some 30 minutes for my io:get_line-based program to scan through the
input compared to 8 minutes for grep. However, I quickly discovered
that io was the bottleneck rather than the regexps. Also to my
surprise, the beam process grew until it had a resident size of 950 Mb
(according to top). Not quite what I had hoped for. I wonder what
would have happened on my machine with 2 Gb RAM if the file had been
three times the size?

I then tried the well-known "open_port({fd,0,1}, [eof,binary,line])"
approach, and ended up in a program that quickly grew until there was
no memory left (>1.2 Gb before top stopped working) and then
*completely* locking up the computer for some 20 minutes before I
finally managed to take beam down by force.

I believe the later issue is the same that was discussed a about a
year ago by Ulf Wiger and others and the suggestion then was to add
some kind of flow control to line oriented port io. So I hereby humbly
submit a patch to add some very very basic flow control. I am sure
that more skilled designers can easily improve it to also handle
io:get_line() on large files without beam growth. I am also sure there
is a corner case or two which I have not thought of.

This is arguably not a bug since piping big chunks of data into beam
was not what the system originally was built for, but I am still
hoping to get away with sending it to erlang-bugs and getting it in
since:

a) It has been experienced by others as well that it is easy to crash
beam if you have big piped input files
b) Currently there is no *fast* way to read data from stdin without
risking beam growth/crash - this is a serious limitation
c) I have provided a patch (which also seems to keep the memory
consumption at more normal levels)


*** erts/emulator/beam/io.c.old 2008-08-01 00:29:16.000000000 +0200
--- erts/emulator/beam/io.c     2008-08-04 22:26:00.000000000 +0200
*************** static void missing_drv_callback(Port *p
*** 2437,2447 ****
--- 2437,2472 ----
  void
  erts_port_ready_input(Port *p, ErlDrvEvent hndl)
  {
+     Process *rp = NULL;
+     ErtsProcLocks rp_locks = ERTS_PROC_LOCK_MSGQ;
+
      ERTS_SMP_CHK_NO_PROC_LOCKS;
      ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(p));

      ASSERT((p->status & ERTS_PORT_SFLGS_DEAD) == 0);

+     /* When using linebuf_io there is a risk of ending up with an ever growing
+      * message queue in the connected process since there is no flow control
+      * and we usually end up with many small messages instead of one large.
+
+      * The obvious disadvantage with the simple flow control below is that a
+      * message queue which has grown for other reasons than io may
temporarily
+      * stop io messages to the controlling process. On the other hand if we
+      * have a message queue of 4*ERL_MESSAGE_BUF_SZ then it is not helping us
+      * to fill it up with even more messages.
+
+      * With this patch at least we will not run out of memory and crash, and
+      * this makes it easier to analyse the problem... */
+
+     if (p->status & ERTS_PORT_SFLG_LINEBUF_IO) {
+         rp = erts_pid2proc(NULL, 0, p->connected, rp_locks);
+         if (rp) {
+            int mq_too_long = rp->msg.len > 4*ERL_MESSAGE_BUF_SZ;
+            erts_smp_proc_unlock(rp, rp_locks);
+            if (mq_too_long) return;
+         }
+     }
+
      if (!p->drv_ptr->ready_input)
        missing_drv_callback(p, hndl, DO_READ);
      else {


BR /Fredrik

PS. So how did the new re library match up to grep with the above
patch? Quite well I would say. Almost two minutes faster than grep
(using the mmap option to grep only made a few seconds difference).
Even though I knew re was fast from previous experiments I was quite
pleasantly surprised. It is still using more memory than grep, for
sure, but still, I am willing to make that trade-off in this case.


$ time otp_src_R12B-3/bin/erl -smp disable -user logreader <
/tmp/messages.4 > output2.txt

real    6m16.410s
user    6m12.910s
sys     0m3.220s

$ time grep -E '(Mar|Apr) *[0-9]+ *0(1|2):' < /tmp/messages.4 > output3.txt

real    8m17.259s
user    8m15.170s
sys     0m1.640s

$ diff output2.txt output3.txt
$
-------------- next part --------------
A non-text attachment was scrubbed...
Name: logreader.erl
Type: application/octet-stream
Size: 544 bytes
Desc: not available
URL: <http://erlang.org/pipermail/erlang-bugs/attachments/20080805/5671ad85/attachment.obj>