Sneak peek at tomorrow's timing insanity

Sneak peek at tomorrow's timing insanity

I encountered something mighty crazy while working on something else tonight. I'll do a full writeup on it tomorrow, but here's a sneak peek with a small brain teaser for those who are so inclined...

Certain versions of the 'script' tool from util-linux have a -t flag which makes it emit timing data on stderr. It gives you a time interval and a number of bytes, and with some careful attention to detail, you can use it to replay interactive sessions. I mentioned this playback stuff in a post earlier this month.

So here's the question: what does this mean?

$ script -t -c "echo -n hello" >/dev/null 2>t
$ cat t
0.903970 5

Does it mean it took 903 milliseconds to print "hello"? Are you sure? Let's run it again.

$ script -t -c "echo -n hello" >/dev/null 2>t
$ cat t
0.287120 5

This time it took "only" 287 milliseconds. That still seems like a really long time to do something so simple.

Now let's do a bunch of them in series and see what it looks like.

$ (for i in `seq 1 10`; do script -t -c "echo -n hello" >/dev/null; done) 
2>t
$ cat t
0.763752 5
0.766626 5
0.769522 5
0.772420 5
0.775333 5
0.778268 5
0.781280 5
0.784057 5
0.786926 5
0.789660 5

Okay... now they're ascending. That is certainly interesting.

Have you figured out what's going on yet? Tune in tomorrow for the rest!