can we measure the traffic between user and kernel mode

Alexandre Courbot gnurou at gmail.com
Sun Jan 30 20:38:23 EST 2011


> I have tried both ways you mentioned.
> in case 1:
> it did interleave the output of standard output with standard error.
> in case 2:
> the standard output seems will be collect for flush at later,
> combine.strace.txt.
> (I attach the testing result for your reference.)
> theoretically, file re-direction should not be effect the content of
> output, right?

That's what I thought too, but it turns out the libc is smarter than
we expected. File redirection *does* affect the order of output, as
testified by your logs. See the non-redirected behavior:

15:55:35.205409 write(1, "\n", 1)       = 1
15:55:35.205517 write(1, "open fail\n", 10) = 10
15:55:35.205628 open("/home/miloody", O_RDONLY) = -1 ENOENT (No such
file or directory)
15:55:35.205745 write(1, "\n", 1)       = 1
15:55:35.205847 write(1, "open fail\n", 10) = 10
15:55:35.205957 open("/home/miloody", O_RDONLY) = -1 ENOENT (No such
file or directory)
15:55:35.206073 write(1, "\n", 1)       = 1
15:55:35.206174 write(1, "open fail\n", 10) = 10
15:55:35.206284 open("/home/miloody", O_RDONLY) = -1 ENOENT (No such
file or directory)
...

and compare it to what happens when we use redirection:

...
15:56:21.105236 open("/home/miloody", O_RDONLY) = -1 ENOENT (No such
file or directory)
15:56:21.105294 open("/home/miloody", O_RDONLY) = -1 ENOENT (No such
file or directory)
15:56:21.105353 open("/home/miloody", O_RDONLY) = -1 ENOENT (No such
file or directory)
15:56:21.105417 write(1, "\nopen fail\n\nopen fail\n\nopen fail"..., 110

Here the libc has grouped all your printfs into one single system call
because of user-space buffering. Fortunately you can prevent this
behavior using unbuffer:

http://linuxcommand.org/man_pages/unbuffer1.html

So your strace invokation would be like:

$ strace -tt stdbuf -o0 -e0 ./foo &>output

Which produces the expected output on my system.

Alex.



More information about the Kernelnewbies mailing list