I was trying to track down a Thunderbird bug where Thunderbird was chewing up CPU cycles. I reported this as bug 363163 at bugzilla. Anyway, I wanted to measure the CPU percentage usage as I tried out doing different things in Thunderbird.
I recently discovered Zenity, a program for displaying various graphical dialogs, including a progress meter which seemed perfect for my needs.
I used the prstat command, piped the output to grep to get rid of the unwanted lines, piped those results to cut to get the field I wanted and then piped that to zenity.
Except I didn’t get anything. I was a little unsure of my syntax on the cut command, so I thought I got it wrong. I tried shortening the pipe by going further and further up the pipe.
I finally got to just the prstat and the grep. If I let it go to the screen, it appeared to work, but if I redirected to an output file, the file was always empty. What gives?
I was checking man pages, looking at the source code for grep and coming up empty. Eventually I happened to let the test run while I was looking somthing up, and lo and behold, the screen suddenly filled with all the expected output! The light dawned.
It was instantly clear to me what was going on. The stdio library buffers output. It was storing the output and then dumping it all at once when the buffer filled up. I had tried using truss to see the behavior from grep, and I could see the reads and no writes, so I assumed that it wasn’t writing at all, but it was really delaying the writes. Doh!
There doesn’t appear to be any way to control this behavior externally, so I just replaced the pipeline with a perl script, which does allow you to control the buffering behavior. Sometimes it is little things that bite you in the most annoying ways.
Technorati tags: topic:[programming]