[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]

Re: Why some Tor servers are slow



Chris Palmer wrote:

Giorgos Pallas writes:



So, something is going wrong specificaly with ssl because if you try
to make other connections to the server (eg web browse:
http://postmortem.csd.auth.gr), it works very fast.So, how could I
further troubleshoot ssl? Using some openssl parameters maybe? Any
ideas?



Try using strace(1) to see where all that time is being spent. The output is likely to be copious, but see the -c option in the man page.




Well, I used strace which was very informative, as long as someone can understand this information!
So I would kindly ask if any unix guru is out there listening, plz have a look and help!
I send the output with strace -c, and without -c which is rather extensive.


So, when I run strace without -c, it was all always running very fast, until these lines :

write(3, "\200\214\1\3\1\0c\0\0\0 \0\0009\0\0008\0\0005\0\0\26\0"..., 142) = 142
read(3, "\26\3\1\0*\2\0", 7) = 7


I mean, I got all the output of strace at once until I saw: "read(3, "
, it then stuck there for some seconds, and then I always got the rest of the response at once.


Anyone any ideas what is happening there?

And also all these files that are said to be missing, do you think they are causing some problems?


gpall@postmortem:~$strace -c openssl s_client -connect 155.207.113.227:9001
CONNECTED(00000003)
depth=1 /O=TOR/CN=masquerade <identity>
verify error:num=19:self signed certificate in certificate chain
verify return:0
---
Certificate chain
0 s:/O=TOR/CN=masquerade
i:/O=TOR/CN=masquerade <identity>
1 s:/O=TOR/CN=masquerade <identity>
i:/O=TOR/CN=masquerade <identity>
---
Server certificate
-----BEGIN CERTIFICATE-----
MIIByDCCATGgAwIBAgIEQ0qX2zANBgkqhkiG9w0BAQUFADAuMQwwCgYDVQQKEwNU
T1IxHjAcBgNVBAMUFW1hc3F1ZXJhZGUgPGlkZW50aXR5PjAeFw0wNTEwMTAxNjMz
MzFaFw0wNTEwMTAxODMzMzFaMCMxDDAKBgNVBAoTA1RPUjETMBEGA1UEAxMKbWFz
cXVlcmFkZTCBnzANBgkqhkiG9w0BAQEFAAOBjQAwgYkCgYEAsSQcnvKs2bUsCZNG
hm7LabcIWi5VQ9hRtrgt1i7YZzeCR2RxYm0CRhysZC3/ZFHIQWi4OQKV7zvziPka
SNjQbXMCI6J9X3eheZKK5ztRvGP+iO6xuh6B23I84aXWgWs2pmknfHJQzLJt7dYs
teXADtt8N1gFK6YzjcshfI8YCrECAwEAATANBgkqhkiG9w0BAQUFAAOBgQCtUSz8
dkLjGOWssFvuzzrLZxd5UBuBkhNTtvtbUTE+fiiWPMInYDdQ+zOWsiBK7QZylNL9
VJnu5iQVLh9VqI4w/X4M4IRyoUcRbXQ8f13FTM7V7C7H9D63tS1qCLLj2VcbRo70
ETnYHCVgFeA62s1p/xCiZ3j1+C3wsUrKdPBKRw==
-----END CERTIFICATE-----
subject=/O=TOR/CN=masquerade
issuer=/O=TOR/CN=masquerade <identity>
---
No client certificate CA names sent
---
SSL handshake has read 1469 bytes and written 344 bytes
---
New, TLSv1/SSLv3, Cipher is EDH-RSA-DES-CBC3-SHA
Server public key is 1024 bit
SSL-Session:
Protocol : TLSv1
Cipher : EDH-RSA-DES-CBC3-SHA
Session-ID:
Session-ID-ctx:
Master-Key: 904F465ED9846114BC635ADEEA677914E1239BD028954ED629BFC29A93F29960F061A9C5DA0A2EEDFC1FF63FAD77969D
Key-Arg : None
Start Time: 1128968737
Timeout : 300 (sec)
Verify return code: 19 (self signed certificate in certificate chain)
---
read:errno=0
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
57.18 0.005641 152 37 write
20.18 0.001991 5 386 getpid
6.08 0.000600 26 23 read
3.44 0.000339 38 9 1 open
3.06 0.000302 302 1 connect
2.60 0.000257 18 14 old_mmap
1.25 0.000123 14 9 close
1.09 0.000108 27 4 munmap
0.80 0.000079 16 5 5 access
0.69 0.000068 9 8 fstat64
0.51 0.000050 10 5 time
0.50 0.000049 8 6 brk
0.47 0.000046 46 1 socket
0.45 0.000044 15 3 mmap2
0.32 0.000032 11 3 select
0.28 0.000028 28 1 stat64
0.19 0.000019 6 3 getuid32
0.18 0.000018 9 2 rt_sigaction
0.14 0.000014 14 1 shutdown
0.13 0.000013 13 1 setsockopt
0.10 0.000010 10 1 uname
0.10 0.000010 10 1 set_thread_area
0.09 0.000009 5 2 geteuid32
0.08 0.000008 4 2 getgid32
0.08 0.000008 4 2 getegid32
------ ----------- ----------- --------- --------- ----------------
100.00 0.009866 530 6 total



And now strace without -c:

execve("/usr/bin/openssl", ["openssl", "s_client", "-connect", "155.207.113.227:9001"], [/* 17 vars */]) = 0
uname({sys="Linux", node="postmortem", ...}) = 0
brk(0) = 0x809d000
old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f90000
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.preload", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=18429, ...}) = 0
old_mmap(NULL, 18429, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7f8b000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/usr/lib/i686/cmov/libssl.so.0.9.7", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\0\205\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=198576, ...}) = 0
old_mmap(NULL, 199344, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xb7f5a000
old_mmap(0xb7f88000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x2e000) = 0xb7f88000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/usr/lib/i686/cmov/libcrypto.so.0.9.7", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0p\300\2"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=1029672, ...}) = 0
old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f59000
old_mmap(NULL, 1043608, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xb7e5a000
old_mmap(0xb7f44000, 73728, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0xea000) = 0xb7f44000
old_mmap(0xb7f56000, 11416, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7f56000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/tls/libdl.so.2", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\320\32"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=9872, ...}) = 0
old_mmap(NULL, 8632, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xb7e57000
old_mmap(0xb7e59000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x2000) = 0xb7e59000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/tls/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0`Z\1\000"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1254468, ...}) = 0
old_mmap(NULL, 1264780, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0xb7d22000
old_mmap(0xb7e4c000, 36864, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0x129000) = 0xb7e4c000
old_mmap(0xb7e55000, 7308, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7e55000
close(3) = 0
old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7d21000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb7d21080, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0
munmap(0xb7f8b000, 18429) = 0
brk(0) = 0x809d000
brk(0x80be000) = 0x80be000
brk(0) = 0x80be000
rt_sigaction(SIGPIPE, {SIG_IGN}, {SIG_DFL}, 8) = 0
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
open("/usr/lib/ssl/openssl.cnf", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=7782, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f8f000
read(3, "#\n# OpenSSL example configuratio"..., 4096) = 4096
read(3, "_name ]\ncountryName\t\t\t= Country "..., 4096) = 3686
read(3, "", 4096) = 0
close(3) = 0
munmap(0xb7f8f000, 4096) = 0
rt_sigaction(SIGPIPE, {SIG_IGN}, {SIG_IGN}, 8) = 0
getpid() = 11689
getpid() = 11689
getpid() = 11689
getuid32() = 1000
geteuid32() = 1000
getgid32() = 1000
getegid32() = 1000
getuid32() = 1000
geteuid32() = 1000
getgid32() = 1000
getegid32() = 1000
stat64("/home/gpall/.rnd", {st_mode=S_IFREG|0600, st_size=1024, ...}) = 0
open("/home/gpall/.rnd", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0600, st_size=1024, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f8f000
read(3, "\232)\324\274\361\310\36\221HAh\326\202\377\351\224\242"..., 4096) = 1024
read(3, "", 4096) = 0
close(3) = 0
munmap(0xb7f8f000, 4096) = 0
getpid() = 11689
getpid() = 11689
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [0], 4) = 0
connect(3, {sa_family=AF_INET, sin_port=htons(9001), sin_addr=inet_addr("155.207.113.227")}, 16) = 0
getpid() = 11689
getpid() = 11689
fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 1), ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f8f000
write(1, "CONNECTED(00000003)\n", 20) = 20
getpid() = 11689
getpid() = 11689
getpid() = 11689
select(4, [3], [3], NULL, NULL) = 1 (out [3])
time(NULL) = 1128968622
getpid() = 11689
brk(0) = 0x80be000
brk(0x80df000) = 0x80df000
getpid() = 11689
getpid() = 11689
getpid() = 11689
open("/dev/urandom", O_RDONLY|O_NONBLOCK|O_NOCTTY) = 4
select(5, [4], NULL, NULL, {0, 10000}) = 1 (in [4], left {0, 10000})
read(4, "\263\306s~3#\301}i\36\305\352\324\n\35\347\276\37C\240"..., 32) = 32
close(4) = 0
getpid() = 11689
getpid() = 11689
getuid32() = 1000
getpid() = 11689
time(NULL) = 1128968622
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(3, "\200\214\1\3\1\0c\0\0\0 \0\0009\0\0008\0\0005\0\0\26\0"..., 142) = 142
read(3, "\26\3\1\0*\2\0", 7) = 7


# comment by gpall -> Here, it was always spending some seconds at: read(3,

time(NULL) = 1128968635
time(NULL) = 1128968635
getpid() = 11689
read(3, "\0&\3\1CJ\261\273\347\31\244\276\6\31\264\336\337\255\30"..., 40) = 40
read(3, "\26\3\1\3\260", 5) = 5
read(3, "\v\0\3\254\0\3\251\0\1\3140\202\1\3100\202\0011\240\3\2"..., 944) = 944
getpid() = 11689
getpid() = 11689
write(2, "depth=1 /O=TOR/CN=masquerade <id"..., 40depth=1 /O=TOR/CN=masquerade <identity>
) = 40
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(2, "verify error:num=19:self signed "..., 65verify error:num=19:self signed certificate in certificate chain
) = 65
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(2, "verify return:0\n", 16verify return:0
) = 16
getpid() = 11689
getpid() = 11689
getpid() = 11689
read(3, "\26\3\1\1\215", 5) = 5
read(3, "\f\0\1\211\0\200\377\377\377\377\377\377\377\377\311\17"..., 397) = 397
read(3, "\26\3\1\0\17", 5) = 5
read(3, "\r\0\0\7\4\3\4\1\2\0\0\16\0\0\0", 15) = 15
time([1128968635]) = 1128968635
getpid() = 11689
getpid() = 11689
write(3, "\26\3\1\0\7\v\0\0\3\0\0\0\26\3\1\0\206\20\0\0\202\0\200"..., 202) = 202
read(3, "\24\3\1\0\1", 5) = 5
read(3, "\1", 1) = 1
read(3, "\26\3\1\0(", 5) = 5
read(3, "4\303\364r3j:\250\26\242pJNeFu[\351c\257\6E\205\270B8\213"..., 40) = 40
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "---\nCertificate chain\n", 22) = 22
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, " 0 s:/O=TOR/CN=masquerade\n", 26) = 26
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, " i:/O=TOR/CN=masquerade <ident"..., 37) = 37
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, " 1 s:/O=TOR/CN=masquerade <ident"..., 37) = 37
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, " i:/O=TOR/CN=masquerade <ident"..., 37) = 37
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "---\n", 4) = 4
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "Server certificate\n", 19) = 19
getpid() = 11689
getpid() = 11689
write(1, "-----BEGIN CERTIFICATE-----\n", 28) = 28
write(1, "MIIByDCCATGgAwIBAgIEQ0qX2zANBgkq"..., 585) = 585
write(1, "ETnYHCVgFeA62s1p/xCiZ3j1+C3wsUrK"..., 41) = 41
write(1, "-----END CERTIFICATE-----\n", 26) = 26
getpid() = 11689
getpid() = 11689
write(1, "subject=/O=TOR/CN=masquerade\n", 29) = 29
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "issuer=/O=TOR/CN=masquerade <ide"..., 39) = 39
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "---\nNo client certificate CA nam"..., 40) = 40
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "---\nSSL handshake has read 1469 "..., 60) = 60
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "---\n", 4) = 4
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "New, TLSv1/SSLv3, Cipher is EDH-"..., 49) = 49
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "Server public key is 1024 bit\n", 30) = 30
getpid() = 11689
getpid() = 11689
write(1, "SSL-Session:\n", 13) = 13
getpid() = 11689
getpid() = 11689
write(1, " Protocol : TLSv1\n", 22) = 22
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, " Cipher : EDH-RSA-DES-CBC3"..., 37) = 37
getpid() = 11689
getpid() = 11689
write(1, " Session-ID: \n", 17) = 17
write(1, " Session-ID-ctx: \n", 21) = 21
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, " Master-Key: D5CCADC8B6686748"..., 113) = 113
getpid() = 11689
getpid() = 11689
write(1, " Key-Arg : None\n", 21) = 21
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, " Start Time: 1128968635\n", 27) = 27
getpid() = 11689
getpid() = 11689
write(1, " Timeout : 300 (sec)\n", 26) = 26
getpid() = 11689
getpid() = 11689
write(1, " Verify return code: 19 (self"..., 74) = 74
getpid() = 11689
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(1, "---\n", 4) = 4
getpid() = 11689
getpid() = 11689
select(4, [0 3], [], NULL, NULL) = 1 (in [3])
read(3, "", 5) = 0
getpid() = 11689
getpid() = 11689
getpid() = 11689
write(2, "read:errno=0\n", 13read:errno=0
) = 13
getpid() = 11689
getpid() = 11689
write(3, "\25\3\1\0\30\240\233\237v\330(\251-\22\256\26I\212~\266"..., 29) = 29
shutdown(3, 0 /* receive */) = 0
close(3) = 0
getpid() = 11689
getpid() = 11689
munmap(0xb7f8f000, 4096) = 0
exit_group(0) = ?