pipe performance problem

[thomas <tom at huno dot net>]

hello,

it seems that the pipe code with recent cygwin versions causes a
performance problem when much data (3.6 MB per second in this case) is
transferred from one program to another.

i use mkisofs to make an iso filesystem from files on the fly and pipe
the output directly to cdrecord which writes the fs to the cd-r. cmd
line looks like this:

mkisofs -J -R -l * | cdrecord -dev=1,0,0 -v -dummy -speed=24 -

with cygwin 1.1.8 this works like expected. however with recent cygwin
versions, f.e. cvs today, i get a buffer underrun in a few seconds. this
usually means the data was not delievered fast enough or not at all.

i've investigated the problem and included a few lines (i got 50MB if
someone wants to see more) from the strace logs at the bottom. basically
what you can see is:

1.1.18

mkisofs reads in 1024 chars from the testfile a few times.
now mkisofs writes about 50 - 250 to stdout. a few microseconds later
cdrecord reads the exact number of bytes from stdin. this happens again
and again until mkisofs reads 1024 chars from the testfile again.

1.3.15

mkisofs reads in 1024 chars from the testfile a few times, then writes
1024 out to stdout the same number of times it read from the file. but
now cdrecord doesn't read in 1024 for every 1024 that were written by
mkisofs. instead it swallows 17048 in one time. sometimes it divides the
17048 in two smaller chunks (like 4096 and 13312), but never more than
two.

it looks like 1.3.15 uses big chunks, and "flushes" them in one
go while 1.1.8 reads/writes small chunks synchronous.

thomas

ps. here are the strace lines:

1.1.18:

   28 3862029 [main] mkisofs 668 fhandler_base::read: returning 1024 chars, binary mode
   25 3862054 [main] mkisofs 668 _read: 1024 = read (3<001/testfile>, 0xA011F28, 1024), bin 4096, errno 2
   28 3862082 [main] mkisofs 668 _read: read (3, 0xA011F28, 1024) blocking, sigcatchers 0
   26 3862108 [main] mkisofs 668 _read: non-interruptible read
   27 3862135 [main] mkisofs 668 fhandler_base::read: returning 1024 chars, binary mode
   25 3862160 [main] mkisofs 668 _read: 1024 = read (3<001/testfile>, 0xA011F28, 1024), bin 4096, errno 2
   27 3862187 [main] mkisofs 668 _read: read (3, 0xA011F28, 1024) blocking, sigcatchers 0
   25 3862212 [main] mkisofs 668 _read: non-interruptible read

   25 3862320 [main] mkisofs 668 fhandler_base::write: binary write
   29 3862349 [main] mkisofs 668 fhandler_base::write: 84 = write (0xA016108, 84)
  132 3862481 [main] mkisofs 668 _write: 84 = write (1, 0xA016108, 84)
   27 3862508 [main] mkisofs 668 _write: write (1, 0xA016108, 68)
   25 3862533 [main] mkisofs 668 fhandler_base::write: binary write
   28 3862561 [main] mkisofs 668 fhandler_base::write: 68 = write (0xA016108, 68)
  129 3862690 [main] mkisofs 668 _write: 68 = write (1, 0xA016108, 68)
   27 3862717 [main] mkisofs 668 _write: write (1, 0xA016108, 85)

  120 3878372 [main] cdrecord 848 fhandler_base::read: returning 84 chars, binary mode
   38 3878410 [main] cdrecord 848 _read: 84 = read (0<{stdin}>, 0xF14599, 49767), bin 4096, errno 2
   25 3878435 [main] cdrecord 848 _read: read (0, 0xF145ED, 49683) blocking, sigcatchers 0
   24 3878459 [main] cdrecord 848 _read: non-interruptible read
  119 3878578 [main] cdrecord 848 fhandler_base::read: returning 68 chars, binary mode
   39 3878617 [main] cdrecord 848 _read: 68 = read (0<{stdin}>, 0xF145ED, 49683), bin 4096, errno 2
   24 3878641 [main] cdrecord 848 _read: read (0, 0xF14631, 49615) blocking, sigcatchers 0
   24 3878665 [main] cdrecord 848 _read: non-interruptible read


1.3.15:

   28  572570 [main] mkisofs 944 fhandler_base::read: returning 1024 chars, binary mode
   26  572596 [main] mkisofs 944 readv: 1024 = readv (3, 0x22D598, 1), errno 0
   27  572623 [main] mkisofs 944 readv: readv (3, 0x22D598, 1) blocking, sigcatchers 0
   26  572649 [main] mkisofs 944 readv: no need to call ready_for_read
   28  572677 [main] mkisofs 944 fhandler_base::read: returning 1024 chars, binary mode
   26  572703 [main] mkisofs 944 readv: 1024 = readv (3, 0x22D598, 1), errno 0
   27  572730 [main] mkisofs 944 readv: readv (3, 0x22D598, 1) blocking, sigcatchers 0
   26  572756 [main] mkisofs 944 readv: no need to call ready_for_read

   25  580608 [main] mkisofs 944 fhandler_base::write: binary write
   28  580636 [main] mkisofs 944 fhandler_base::write: 1024 = write (0x475D30, 1024)
   26  580662 [main] mkisofs 944 writev: 1024 = write (1, 0x22D328, 1), errno 0
   27  580689 [main] mkisofs 944 writev: writev (1, 0x22D328, 1)
   25  580714 [main] mkisofs 944 fhandler_base::write: binary write
   38  580752 [main] mkisofs 944 fhandler_base::write: 1024 = write (0x476130, 1024)
   26  580778 [main] mkisofs 944 writev: 1024 = write (1, 0x22D328, 1), errno 0
   27  580805 [main] mkisofs 944 writev: writev (1, 0x22D328, 1)

10586  586468 [main] cdrecord 1156 peek_pipe: /dev/piper, ready for read
   48  586516 [main] cdrecord 1156 fhandler_base::ready_for_read: read_ready 1, avail 1
   73  586589 [main] cdrecord 1156 fhandler_base::read: returning 17408 chars, binary mode
   31  586620 [main] cdrecord 1156 readv: 17408 = readv (0, 0x22D618, 1), errno 9
   28  586648 [main] cdrecord 1156 readv: readv (0, 0x22D618, 1) blocking, sigcatchers 0
10541  597189 [main] cdrecord 1156 peek_pipe: /dev/piper, ready for read
   32  597221 [main] cdrecord 1156 fhandler_base::ready_for_read: read_ready 1, avail 1
   46  597267 [main] cdrecord 1156 fhandler_base::read: returning 9216 chars, binary mode
   28  597295 [main] cdrecord 1156 readv: 9216 = readv (0, 0x22D618, 1), errno 9
   63  597358 [main] cdrecord 1156 readv: readv (0, 0x22D618, 1) blocking, sigcatchers 0
   35  597393 [main] cdrecord 1156 peek_pipe: /dev/piper, ready for read
   58  597451 [main] cdrecord 1156 fhandler_base::ready_for_read: read_ready 1, avail 1
   45  597496 [main] cdrecord 1156 fhandler_base::read: returning 8192 chars, binary mode
   28  597524 [main] cdrecord 1156 readv: 8192 = readv (0, 0x22D618, 1), errno 9
   27  597551 [main] cdrecord 1156 readv: readv (0, 0x22D618, 1) blocking, sigcatchers 0


--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Bug reporting:         http://cygwin.com/bugs.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/