Wie kann ich feststellen, ob der Pipe-Puffer voll ist?

Ich leite die Ausgabe eines Programms in ein Perl, das ich geschrieben habe. Dies ist ein langwieriger Prozess, manchmal Tage, daher möchte ich herausfinden, wo meine Engpässe liegen, und versuchen, sie zu öffnen. Ich möchte wissen, ob Daten schneller in mein Skript geleitet werden, als mein Skript sie verarbeiten kann. In diesem Fall werde ich versuchen, mein Skript zu optimieren, aber nicht, wenn ich es nicht muss. Ich sehe die Rede davon, dass ein Flag gesetzt wird, wenn der Puffer voll ist, wodurch weitere Schreibvorgänge verhindert werden. Wie kann ich jedoch überprüfen, ob oder wie oft dieses Flag gesetzt ist? Irgendwelche Ideen?

Ich würde Ihr Perl-Skript mit einem Systemaufruf-Trace-Tool verfolgen: strace(Linux), dtruss(OS X), ktrace(FreeBSD), truss(Solaris) usw. Das Ziel wäre zu sehen, wie viel Zeit Ihr Perl-Skript damit verbringt, darauf zu warten, es zu lesen stdin und wie viel Zeit das andere Programm damit verbringt, darauf zu warten, in sein stdout zu schreiben.

Hier teste ich dies mit dem Autor als Engpass:

terminal 1$ gzip -c < /dev/urandom | cat > /dev/null

terminal 2$ ps auxw | egrep 'gzip|cat'
slamb    25311 96.0  0.0  2852  516 pts/0    R+   23:35   3:40 gzip -c
slamb    25312  0.8  0.0  2624  336 pts/0    S+   23:35   0:01 cat

terminal 2$ strace -p 25312 -s 0 -rT -e trace=read
Process 25312 attached - interrupt to quit
     0.000000 read(0, ""..., 4096) = 4096 <0.005207>
     0.005531 read(0, ""..., 4096) = 4096 <0.000051>

Die erste Zahl ist hier die Zeit seit dem Start des vorherigen Systemaufrufs, und die letzte Zahl ist die Zeit, die im Systemaufruf verbracht wurde. Also können wir mit Perl ein bisschen nachbearbeiten, um es zu aggregieren ... [*]

terminal 2$ strace -p 25312 -s 0 -rT -e trace=read 2>&1 | perl -nle 'm{^\s*([\d.]+) read\(0, .*<([\d.]+)>} or next; $total_work += $1 - $last_wait; $total_wait += $2; $last_wait = $2; print "working for $total_work sec, waiting for $total_wait sec"; $last_wait = $2;'
working for 0 sec, waiting for 0.005592 sec
...
working for 0.305356 sec, waiting for 2.28624900000002 sec
...

terminal 2$ strace -p 25311 -s 0 -rT -e trace=write 2>&1 | perl -nle 'm{^\s*([\d.]+) write\(1, .*<([\d.]+)>} or next; $total_work += $1 - $last_wait; $total_wait += $2; $last_wait = $2; print "working for $total_work sec, waiting for $total_wait sec"; $last_wait = $2;'
...
working for 5.15862000000001 sec, waiting for 0.0555740000000007 sec
...

Sie könnten schicker werden und ein SystemTap- oder DTrace-Skript erstellen, das beide Seiten gleichzeitig verfolgt, nur den richtigen Dateideskriptor verfolgt und jede Sekunde oder so eine nette Statusaktualisierung druckt, mit wie viel Prozent der Zeit jeder auf den anderen gewartet hat.

[*] - Warnung: Meine grobe Aggregation ist nicht ganz richtig, wenn Lese- / Schreibvorgänge für andere Dateideskriptoren aufgerufen werden. In diesem Fall wird die Arbeitszeit unterschätzt.

Die dtrace-Version ist eigentlich ziemlich ordentlich.

terminal 1$ gzip -c < /dev/urandom | cat > /dev/null

terminal 2$ ps aux | egrep 'gzip| cat'
slamb    54189  95.8  0.0   591796    584 s006  R+   12:49AM  22:49.55 gzip -c
slamb    54190   0.4  0.0   599828    392 s006  S+   12:49AM   0:06.08 cat

terminal 2$ cat > pipe.d <<'EOF'
#!/usr/sbin/dtrace -qs

BEGIN
{
  start = timestamp;
  writer_blocked = 0;
  reader_blocked = 0;
}

tick-1s, END
{
  this->elapsed = timestamp - start;
  printf("since startup, writer blocked %3d%% of time, reader %3d%% of time\n",
         100 * writer_blocked / this->elapsed,
         100 * reader_blocked / this->elapsed);
}

syscall::write:entry
/pid == $1 && arg0 == 1/
{
  self->entry = timestamp;
}

syscall::write:return
/pid == $1 && self->entry != 0/
{
  writer_blocked += timestamp - self->entry;
  self->entry = 0;
}

syscall::read:entry
/pid == $2 && arg0 == 0/
{
  self->entry = timestamp;
}

syscall::read:return
/pid == $2 && self->entry != 0/
{
  reader_blocked += timestamp - self->entry;
  self->entry = 0;
}
EOF

terminal 2$ chmod u+x pipe.d
terminal 2$ sudo ./pipe.d 54189 54190
since startup, writer blocked   0% of time, reader  98% of time
since startup, writer blocked   0% of time, reader  99% of time
since startup, writer blocked   0% of time, reader  99% of time
since startup, writer blocked   0% of time, reader  99% of time
since startup, writer blocked   0% of time, reader  99% of time
^C
since startup, writer blocked   0% of time, reader  99% of time

Und die SystemTap-Version:

terminal 1$ gzip -c /dev/urandom | cat > /dev/null

terminal 2$ ps auxw | egrep 'gzip| cat'
slamb     3405  109  0.0   4356   584 pts/1    R+   02:57   0:04 gzip -c /dev/urandom
slamb     3406  0.2  0.0  10848   588 pts/1    S+   02:57   0:00 cat

terminal 2$ cat > probes.stp <<'EOF'
#!/usr/bin/env stap

global start
global writer_pid
global writes
global reader_pid
global reads

probe begin {
  start = gettimeofday_us()
  writer_pid = strtol(argv[1], 10)
  reader_pid = strtol(argv[2], 10)
}

probe timer.s(1), end {
  elapsed = gettimeofday_us() - start
  printf("since startup, writer blocked %3d%% of time, reader %3d%% of time\n",
         100 * @sum(writes) / elapsed,
         100 * @sum(reads) / elapsed)
}

probe syscall.write.return {
  if (pid() == writer_pid && $fd == 1)
    writes <<< gettimeofday_us() - @entry(gettimeofday_us())
}

probe syscall.read.return {
  if (pid() == reader_pid && $fd == 0)
    reads <<< gettimeofday_us() - @entry(gettimeofday_us())
}
EOF

terminal 2$ chmod a+x probes.stp
terminal 2$ sudo ./pipe.stp 3405 3406
since startup, writer blocked   0% of time, reader  99% of time
...

Sie können einen pv -TCBefehl in Ihre Pipeline einfügen :

cmd1 | pv -TC | cmd2

pvverwendet einen eigenen Puffer und -Tgibt an, wie voll er durchschnittlich in 1-Sekunden-Perioden ist (standardmäßig).

Wenn es immer 100% ist, bedeutet dies, dass die cmd1Produktion schneller produziert als cmd2verbraucht wird. Wenn nicht, dann ist es umgekehrt. Beachten Sie, dass die Rohre selbst 64 KB aufnehmen können.

Siehe auch -B, um pvdie Puffergröße anzugeben . Sie können mehrere pvs wie folgt verwenden:

$ cmd1 | pv -cCTrbN 'cmd1 -> cmd2' | cmd2 | pv -cCTrbN 'cmd2 -> cmd3' | cmd3
cmd1 -> cmd2: 1.92GiB { 53%} [ 387MiB/s]
cmd2 -> cmd3: 1.92GiB {  0%} [ 387MiB/s]