タグ「centos」が付けられているもの

PreforkのApacheの動作を確認する
ここではプロセスを1個にしぼって
MaxRequestsPerChild 2にしたときの挙動を確認する
  

dStartServers       1
MinSpareServers    1
MaxSpareServers    1
ServerLimit      1
MaxClients       1
MaxRequestsPerChild  2

ログのフォーマットを変更して処理を行ってるapacheのプロセスIDを表示するようにする
参考: Apache モジュール mod_log_config : カスタムログ書式
  
LogFormat "%h %l %u %t \"%r\" %>s %b %P" common_plus_pid
CustomLog logs/sandbox.de4u.net-access_log common_plus_pid

apacheを再起動してログを確認する
最後の数字がプロセスIDになる
  
# tail -f /var/log/httpd/sandbox.de4u.net-access_log
10.0.1.1 - - [20/Sep/2009:22:14:42 +0900] "GET / HTTP/1.1" 401 486 25822
10.0.1.1 - yoshimax [20/Sep/2009:22:14:42 +0900] "GET / HTTP/1.1" 200 7 25822
10.0.1.1 - yoshimax [20/Sep/2009:22:14:44 +0900] "GET /favicon.ico HTTP/1.1" 404 294 25825
10.0.1.1 - yoshimax [20/Sep/2009:22:14:47 +0900] "GET / HTTP/1.1" 200 7 25825
10.0.1.1 - yoshimax [20/Sep/2009:22:14:49 +0900] "GET /favicon.ico HTTP/1.1" 404 294 25826
10.0.1.1 - yoshimax [20/Sep/2009:22:14:57 +0900] "GET / HTTP/1.1" 200 7 25826
10.0.1.1 - yoshimax [20/Sep/2009:22:14:59 +0900] "GET /favicon.ico HTTP/1.1" 404 294 25827
10.0.1.1 - - [20/Sep/2009:22:19:16 +0900] "GET / HTTP/1.1" 401 486 25827
10.0.1.1 - yoshimax [20/Sep/2009:22:19:18 +0900] "GET / HTTP/1.1" 200 7 25836
10.0.1.1 - yoshimax [20/Sep/2009:22:19:18 +0900] "GET /favicon.ico HTTP/1.1" 404 294 25836
プロセスIDを確認する
  
# ps auxww|grep httpd
root     25809  0.0  0.5  25444 10496 ?        Ss   22:14   0:00 /usr/sbin/httpd
apache   25827  0.0  0.3  25508  6232 ?        S    22:14   0:00 /usr/sbin/httpd
  
# ps auxww|grep httpd
root     25809  0.0  0.5  25444 10496 ?        Ss   22:14   0:00 /usr/sbin/httpd
apache   25837  0.0  0.2  25444  5216 ?        S    22:19   0:00 /usr/sbin/httpd
2回アクセスがある度にプロセスIDが変わっているのが確認できる
MaxRequestsPerChildの挙動は確認できたので
ここでMaxRequestsPerChild 10にして再起動する
ではstrace でapacheのプロセスで何が行われているか確認してみよう
traceを行う為にプロセスのIDが必要なのでhttpdのプロセスIDを確認する
  
# ps auxww|grep httpd
root     25893  0.2  0.5  25444 10496 ?        Ss   22:28   0:00 /usr/sbin/httpd
apache   25906  0.0  0.2  25444  5216 ?        S    22:28   0:00 /usr/sbin/httpd
子プロセスのIDがわかったのでstraceを行ってみよう
  
# strace -f -p 25906
Process 25906 attached - interrupt to quit
epoll_wait(25, 
と表示される epoll_wait(25, の部分でHTTPが待ち受け状態になっているのが確認できる
ここで Apacheにリクエストを投げてみよう http://sandbox.de4u.net/に ブラウザからアクセスをおこなってみよう
http://sandbox.de4u.net/のディレクティブにはindex.htmlが置いてあり
# cat /home/www/sandbox/htdocs/index.html
sandbox
というファイルが置いてある
アクセスを行うと以下のstraceログが出力される
  
Process 25906 attached - interrupt to quit
epoll_wait(25, 
{{EPOLLIN, {u32=145139040, u64=13799927267350455648}}}, 2, -1) = 1
accept(4, {sa_family=AF_INET6, sin6_port=htons(33398), inet_pton(AF_INET6, "::ffff:10.0.1.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 27
semop(3670020, 0x5b0dbe, 1)             = 0
getsockname(27, {sa_family=AF_INET6, sin6_port=htons(80), inet_pton(AF_INET6, "::ffff:10.0.1.100", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
fcntl64(27, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(27, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(27, "GET / HTTP/1.1\r\nHost: sandbox.dr"..., 8000) = 543
gettimeofday({1253453446, 493582}, NULL) = 0
stat64("/home/www/sandbox/htdocs/", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
open("/etc/httpd/conf/.httpasswd", O_RDONLY|O_LARGEFILE) = 28
fstat64(28, {st_mode=S_IFREG|0644, st_size=41, ...}) = 0
read(28, "dev:RXpxSyJE\nmax:.kBr"..., 4096) = 41
close(28)                               = 0
time(NULL)                              = 1253453446
stat64("/home/www/sandbox/config/environment.rb", 0xbf832a9c) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253453446
stat64("/home/www/sandbox/config.ru", 0xbf832a9c) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253453446
stat64("/home/www/sandbox/passenger_wsgi.py", 0xbf832a9c) = -1 ENOENT (No such file or directory)
stat64("/home/www/sandbox/htdocs/index.php", 0xbf832cec) = -1 ENOENT (No such file or directory)
lstat64("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/www", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
lstat64("/home/www/sandbox", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
lstat64("/home/www/sandbox/htdocs", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
lstat64("/home/www/sandbox/htdocs/index.php", 0xbf832cec) = -1 ENOENT (No such file or directory)
open("/etc/httpd/conf/.httpasswd", O_RDONLY|O_LARGEFILE) = 28
fstat64(28, {st_mode=S_IFREG|0644, st_size=41, ...}) = 0
read(28, "dev:m0xVyJE\nmax:.kBjr"..., 4096) = 41
close(28)                               = 0
time(NULL)                              = 1253453446
stat64("/home/www/sandbox/config/environment.rb", 0xbf83299c) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253453446
stat64("/home/www/sandbox/config.ru", 0xbf83299c) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253453446
stat64("/home/www/sandbox/passenger_wsgi.py", 0xbf83299c) = -1 ENOENT (No such file or directory)
stat64("/home/www/sandbox/htdocs/index.html", {st_mode=S_IFREG|0777, st_size=7, ...}) = 0
open("/etc/httpd/conf/.httpasswd", O_RDONLY|O_LARGEFILE) = 28
fstat64(28, {st_mode=S_IFREG|0644, st_size=41, ...}) = 0
read(28, "dev:pxVyJE\nmax:.kBjr"..., 4096) = 41
close(28)                              = 0
time(NULL)                              = 1253453446
stat64("/home/www/sandbox/config/environment.rb", 0xbf83299c) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253453446
stat64("/home/www/sandbox/config.ru", 0xbf83299c) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253453446
stat64("/home/www/sandbox/passenger_wsgi.py", 0xbf83299c) = -1 ENOENT (No such file or directory)
open("/home/www/sandbox/htdocs/index.html", O_RDONLY|O_LARGEFILE) = 28
mmap2(NULL, 7, PROT_READ, MAP_SHARED, 28, 0) = 0xb7f3e000
writev(27, [{"HTTP/1.1 200 OK\r\nDate: Sun, 20 S"..., 260}, {"sandbox", 7}], 2) = 267
munmap(0xb7f3e000, 7)                   = 0
write(22, "10.0.1.1 - yoshimax [20/Sep/2009"..., 78) = 78
shutdown(27, 1 /* send */)              = 0
poll([{fd=27, events=POLLIN}], 1, 2000) = 1 ([{fd=27, revents=POLLIN|POLLHUP}])
read(27, "", 512)                       = 0
close(27)                               = 0
read(8, 0xbf833073, 1)                  = -1 EAGAIN (Resource temporarily unavailable)
close(28)                               = 0
semop(3670020, 0x5b0db8, 1)             = 0
epoll_wait(25, 
straceを行うとLinuxのシステムコールレベルで何が行われているか確認できる
Linuxのシステムコール関数は、ひとつづつJM Project /JM/html/LDP_man-pages/man2で確認をしていけば内部でどのような動作が行われているか理解できるはずだ。
つぎにphpから外部のサイトのデータを取得した場合のapacheのプロセスをトレースしてみよう
  
<?php
$file = fopen("http://www.google.com/", "r");
while (!feof ($file)) {
  $line = fgets ($file, 1024);
  print	$line;
}
fclose($file);
?>
上記のプログラムにアクセスした場合のstraceのログは以下のようになる
  
# strace -f -p 26019
Process 26025 attached - interrupt to quit
epoll_wait(25, 
{{EPOLLIN, {u32=145139040, u64=13799927404789409120}}}, 2, -1) = 1
accept(4, {sa_family=AF_INET6, sin6_port=htons(46673), inet_pton(AF_INET6, "::ffff:10.0.1.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 27
semop(3670020, 0x5b0dbe, 1)             = 0
getsockname(27, {sa_family=AF_INET6, sin6_port=htons(80), inet_pton(AF_INET6, "::ffff:10.0.1.100", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
fcntl64(27, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(27, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(27, "GET /test1.php HTTP/1.1\r\nHost: s"..., 8000) = 552
gettimeofday({1253455264, 425412}, NULL) = 0
stat64("/home/www/sandbox/htdocs/test1.php", {st_mode=S_IFREG|0664, st_size=141, ...}) = 0
open("/etc/httpd/conf/.httpasswd", O_RDONLY|O_LARGEFILE) = 28
fstat64(28, {st_mode=S_IFREG|0644, st_size=41, ...}) = 0
read(28, "dev:09VyJE\nmax:.kBjr"..., 4096) = 41
close(28)                               = 0
time(NULL)                              = 1253455264
stat64("/home/www/sandbox/config/environment.rb", 0xbf832abc) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253455264
stat64("/home/www/sandbox/config.ru", 0xbf832abc) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253455264
stat64("/home/www/sandbox/passenger_wsgi.py", 0xbf832abc) = -1 ENOENT (No such file or directory)
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
rt_sigaction(SIGPROF, {0x5421340, [PROF], SA_RESTART}, {SIG_DFL, [], 0}, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
gettimeofday({1253455264, 428961}, NULL) = 0
getcwd("/", 4095)                       = 2
chdir("/home/www/sandbox/htdocs")       = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={30, 0}}, NULL) = 0
rt_sigaction(SIGPROF, {0x5421340, [PROF], SA_RESTART}, {0x5421340, [PROF], SA_RESTART}, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
time(NULL)                              = 1253455264
lstat64("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/www", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
lstat64("/home/www/sandbox", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
lstat64("/home/www/sandbox/htdocs", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
lstat64("/home/www/sandbox/htdocs/test1.php", {st_mode=S_IFREG|0664, st_size=141, ...}) = 0
open("/home/www/sandbox/htdocs/test1.php", O_RDONLY) = 28
fstat64(28, {st_mode=S_IFREG|0664, st_size=141, ...}) = 0
lseek(28, 0, SEEK_CUR)                  = 0
brk(0x8af6000)                          = 0x8af6000
read(28, "<?php\n$file = fopen(\"http://www."..., 8192) = 141
read(28, "", 8192)                      = 0
read(28, "", 8192)                      = 0
close(28)                               = 0
socket(PF_INET6, SOCK_DGRAM, IPPROTO_IP) = 28
close(28)                               = 0
open("/etc/hosts", O_RDONLY)            = 28
fcntl64(28, F_GETFD)                    = 0
fcntl64(28, F_SETFD, FD_CLOEXEC)        = 0
fstat64(28, {st_mode=S_IFREG|0644, st_size=187, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f3e000
read(28, "# Do not remove the following li"..., 4096) = 187
read(28, "", 4096)                      = 0
close(28)                               = 0
munmap(0xb7f3e000, 4096)                = 0
open("/etc/hosts", O_RDONLY)            = 28
fcntl64(28, F_GETFD)                    = 0
fcntl64(28, F_SETFD, FD_CLOEXEC)        = 0
fstat64(28, {st_mode=S_IFREG|0644, st_size=187, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f3e000
read(28, "# Do not remove the following li"..., 4096) = 187
read(28, "", 4096)                      = 0
close(28)                               = 0
munmap(0xb7f3e000, 4096)                = 0
open("/etc/ld.so.cache", O_RDONLY)      = 28
fstat64(28, {st_mode=S_IFREG|0644, st_size=34002, ...}) = 0
mmap2(NULL, 34002, PROT_READ, MAP_PRIVATE, 28, 0) = 0xb7f36000
close(28)                               = 0
open("/lib/libnss_dns.so.2", O_RDONLY)  = 28
read(28, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\240\v\0\0004\0\0\0"..., 512) = 512
fstat64(28, {st_mode=S_IFREG|0755, st_size=21876, ...}) = 0
mmap2(NULL, 20612, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 28, 0) = 0x82a000
mmap2(0x82e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 28, 0x3) = 0x82e000
close(28)                               = 0
mprotect(0x82e000, 4096, PROT_READ)     = 0
munmap(0xb7f36000, 34002)               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.0.1.1")}, 28) = 0
fcntl64(28, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(28, F_SETFL, O_RDWR|O_NONBLOCK) = 0
gettimeofday({1253455264, 437877}, NULL) = 0
poll([{fd=28, events=POLLOUT}], 1, 0)   = 1 ([{fd=28, revents=POLLOUT}])
send(28, "\220#\1\0\0\1\0\0\0\0\0\0\3www\6google\3com\0\0\34\0\1", 32, MSG_NOSIGNAL) = 32
poll([{fd=28, events=POLLIN}], 1, 5000) = 1 ([{fd=28, revents=POLLIN}])
ioctl(28, FIONREAD, [52])               = 0
recvfrom(28, "\220#\201\200\0\1\0\1\0\0\0\0\3www\6google\3com\0\0\34\0\1"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.0.1.1")}, [16]) = 52
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.0.1.1")}, 28) = 0
fcntl64(28, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(28, F_SETFL, O_RDWR|O_NONBLOCK) = 0
gettimeofday({1253455264, 445300}, NULL) = 0
poll([{fd=28, events=POLLOUT}], 1, 0)   = 1 ([{fd=28, revents=POLLOUT}])
send(28, " \246\1\0\0\1\0\0\0\0\0\0\3www\6google\3com\0\0\1\0\1", 32, MSG_NOSIGNAL) = 32
poll([{fd=28, events=POLLIN}], 1, 5000) = 1 ([{fd=28, revents=POLLIN}])
ioctl(28, FIONREAD, [116])              = 0
recvfrom(28, " \246\201\200\0\1\0\5\0\0\0\0\3www\6google\3com\0\0\1\0\1"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.0.1.1")}, [16]) = 116
close(28)                               = 0
socket(PF_NETLINK, SOCK_RAW, 0)         = 28
bind(28, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(28, {sa_family=AF_NETLINK, pid=26025, groups=00000000}, [12]) = 0
time(NULL)                              = 1253455264
sendto(28, "\24\0\0\0\26\0\1\3\2405\266J\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(28, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"<\0\0\0\24\0\2\0\2405\266J\251e\0\0\2\10\200\376\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 196
recvmsg(28, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"@\0\0\0\24\0\2\0\2405\266J\251e\0\0\n\200\200\376\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 384
recvmsg(28, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\24\0\0\0\3\0\2\0\2405\266J\251e\0\0\0\0\0\0\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("66.249.89.147")}, 16) = 0
getsockname(28, {sa_family=AF_INET, sin_port=htons(44684), sin_addr=inet_addr("10.0.1.100")}, [16]) = 0
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("66.249.89.103")}, 16) = 0
getsockname(28, {sa_family=AF_INET, sin_port=htons(49718), sin_addr=inet_addr("10.0.1.100")}, [16]) = 0
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("66.249.89.104")}, 16) = 0
getsockname(28, {sa_family=AF_INET, sin_port=htons(39169), sin_addr=inet_addr("10.0.1.100")}, [16]) = 0
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("66.249.89.99")}, 16) = 0
getsockname(28, {sa_family=AF_INET, sin_port=htons(51659), sin_addr=inet_addr("10.0.1.100")}, [16]) = 0
close(28)                               = 0
gettimeofday({1253455264, 459267}, NULL) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 28
fcntl64(28, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(28, F_SETFL, O_RDWR|O_NONBLOCK) = 0
connect(28, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("66.249.89.147")}, 16) = -1 EINPROGRESS (Operation now in progress)
poll([{fd=28, events=POLLIN|POLLOUT|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLOUT}])
getsockopt(28, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
fcntl64(28, F_SETFL, O_RDWR)            = 0
send(28, "GET / HTTP/1.0\r\n", 16, 0)   = 16
send(28, "Host: www.google.com\r\n", 22, 0) = 22
send(28, "\r\n", 2, 0)                  = 2
poll([{fd=28, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 0 (Timeout)
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "HTTP/1.0 302 Found\r\nLocation: ht"..., 8192, 0) = 792
close(28)                               = 0
open("/etc/hosts", O_RDONLY)            = 28
fcntl64(28, F_GETFD)                    = 0
fcntl64(28, F_SETFD, FD_CLOEXEC)        = 0
fstat64(28, {st_mode=S_IFREG|0644, st_size=187, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f3e000
read(28, "# Do not remove the following li"..., 4096) = 187
read(28, "", 4096)                      = 0
close(28)                               = 0
munmap(0xb7f3e000, 4096)                = 0
open("/etc/hosts", O_RDONLY)            = 28
fcntl64(28, F_GETFD)                    = 0
fcntl64(28, F_SETFD, FD_CLOEXEC)        = 0
fstat64(28, {st_mode=S_IFREG|0644, st_size=187, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f3e000
read(28, "# Do not remove the following li"..., 4096) = 187
read(28, "", 4096)                      = 0
close(28)                               = 0
munmap(0xb7f3e000, 4096)                = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.0.1.1")}, 28) = 0
fcntl64(28, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(28, F_SETFL, O_RDWR|O_NONBLOCK) = 0
gettimeofday({1253455264, 531407}, NULL) = 0
poll([{fd=28, events=POLLOUT}], 1, 0)   = 1 ([{fd=28, revents=POLLOUT}])
send(28, "\304\210\1\0\0\1\0\0\0\0\0\0\3www\6google\2co\2jp\0\0\34"..., 34, MSG_NOSIGNAL) = 34
poll([{fd=28, events=POLLIN}], 1, 5000) = 1 ([{fd=28, revents=POLLIN}])
ioctl(28, FIONREAD, [82])               = 0
recvfrom(28, "\304\210\201\200\0\1\0\2\0\0\0\0\3www\6google\2co\2jp\0\0\34"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.0.1.1")}, [16]) = 82
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.0.1.1")}, 28) = 0
fcntl64(28, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(28, F_SETFL, O_RDWR|O_NONBLOCK) = 0
gettimeofday({1253455264, 544028}, NULL) = 0
poll([{fd=28, events=POLLOUT}], 1, 0)   = 1 ([{fd=28, revents=POLLOUT}])
send(28, "QU\1\0\0\1\0\0\0\0\0\0\3www\6google\2co\2jp\0\0\1"..., 34, MSG_NOSIGNAL) = 34
poll([{fd=28, events=POLLIN}], 1, 5000) = 1 ([{fd=28, revents=POLLIN}])
ioctl(28, FIONREAD, [146])              = 0
recvfrom(28, "QU\201\200\0\1\0\6\0\0\0\0\3www\6google\2co\2jp\0\0\1"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("10.0.1.1")}, [16]) = 146
close(28)                               = 0
socket(PF_NETLINK, SOCK_RAW, 0)         = 28
bind(28, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(28, {sa_family=AF_NETLINK, pid=26025, groups=00000000}, [12]) = 0
time(NULL)                              = 1253455264
sendto(28, "\24\0\0\0\26\0\1\3\2405\266J\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(28, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"<\0\0\0\24\0\2\0\2405\266J\251e\0\0\2\10\200\376\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 196
recvmsg(28, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"@\0\0\0\24\0\2\0\2405\266J\251e\0\0\n\200\200\376\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 384
recvmsg(28, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\24\0\0\0\3\0\2\0\2405\266J\251e\0\0\0\0\0\0\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("66.249.89.147")}, 16) = 0
getsockname(28, {sa_family=AF_INET, sin_port=htons(38813), sin_addr=inet_addr("10.0.1.100")}, [16]) = 0
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("66.249.89.103")}, 16) = 0
getsockname(28, {sa_family=AF_INET, sin_port=htons(60447), sin_addr=inet_addr("10.0.1.100")}, [16]) = 0
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("66.249.89.104")}, 16) = 0
getsockname(28, {sa_family=AF_INET, sin_port=htons(60741), sin_addr=inet_addr("10.0.1.100")}, [16]) = 0
close(28)                               = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 28
connect(28, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("66.249.89.99")}, 16) = 0
getsockname(28, {sa_family=AF_INET, sin_port=htons(49633), sin_addr=inet_addr("10.0.1.100")}, [16]) = 0
close(28)                               = 0
gettimeofday({1253455264, 557993}, NULL) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 28
fcntl64(28, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(28, F_SETFL, O_RDWR|O_NONBLOCK) = 0
connect(28, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("66.249.89.147")}, 16) = -1 EINPROGRESS (Operation now in progress)
poll([{fd=28, events=POLLIN|POLLOUT|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLOUT}])
getsockopt(28, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
fcntl64(28, F_SETFL, O_RDWR)            = 0
send(28, "GET / HTTP/1.0\r\n", 16, 0)   = 16
send(28, "Host: www.google.co.jp\r\n", 24, 0) = 24
send(28, "\r\n", 2, 0)                  = 2
poll([{fd=28, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 0) = 0 (Timeout)
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "HTTP/1.0 200 OK\r\nDate: Sun, 20 S"..., 8192, 0) = 1418
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "nction _gjp(){!(window._gjwl.has"..., 8192, 0) = 1418
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "r:1px solid;border-color:#c9d7f1"..., 8192, 0) = 1803
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "e.co.jp/?hl=ja&tab=wb\" onclick=g"..., 8192, 0) = 1418
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "lpadding=0 cellspacing=0><tr val"..., 8192, 0) = 1418
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "f=\"http://news.google.co.jp/nwsh"..., 8192, 0) = 1418
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "wi\"><div class=plwi2><a href=\"ht"..., 8192, 0) = 1418
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "/div></li><li class=\"gib plpr\"><"..., 8192, 0) = 1650
writev(27, [{"HTTP/1.1 200 OK\r\nDate: Sun, 20 S"..., 199}, {"27ae\r\n", 6}, {"<html><head><meta http-equiv=\"co"..., 5043}, {"p/ig%3Fhl%3Dja%26source%3Diglk&u"..., 5115}, {"\r\n", 2}], 5) = 10365
poll([{fd=28, events=POLLIN|POLLERR|POLLHUP}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
recv(28, "", 8192, 0)                   = 0
close(28)                               = 0
chdir("/")                              = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
writev(27, [{"4ec\r\n", 5}, {"ef=\"/intl/ja/options/\">\203T\201[\203r\203X\210"..., 1260}, {"\r\n", 2}, {"0\r\n\r\n", 5}], 4) = 1272
write(22, "10.0.1.1 - yoshimax [20/Sep/2009"..., 91) = 91
shutdown(27, 1 /* send */)              = 0
poll([{fd=27, events=POLLIN}], 1, 2000) = 1 ([{fd=27, revents=POLLIN|POLLHUP}])
read(27, "", 512)                       = 0
close(27)                               = 0
read(8, 0xbf833093, 1)                  = -1 EAGAIN (Resource temporarily unavailable)
semop(3670020, 0x5b0db8, 1)             = 0
epoll_wait(25, 
システムコールのsocketが呼ばれ外部サイトの情報を取得しているのが確認できる
最後にphpからmysqlに繋いだ場合のapacheのプロセスをトレースしてみる mysqlへの接続はシステムコールレベルではどの関数が呼ばれているのでしょうか。
  
<?php
$connect = mysql_connect("localhost", "mtuser", "JoAl24u");
mysql_select_db("mt_sandbox");
$sql = "SELECT * FROM mt_blog";                                                                         
$qu = mysql_query($sql, $connect);                                                                      

while ($row = mysql_fetch_array($qu)) {
  print_r($row);
 }                                                                                                      
mysql_close($connect);
?>
アパッチのプロセスをstraceしてみる
  
# strace -f -p 26183
Process 26183 attached - interrupt to quit
epoll_wait(25, 
{{EPOLLIN, {u32=147690928, u64=13810652316087195056}}}, 2, -1) = 1
accept(4, {sa_family=AF_INET6, sin6_port=htons(37027), inet_pton(AF_INET6, "::ffff:10.0.1.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 27
semop(3866628, 0x4cfdbe, 1)             = 0
getsockname(27, {sa_family=AF_INET6, sin6_port=htons(80), inet_pton(AF_INET6, "::ffff:10.0.1.100", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
fcntl64(27, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(27, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(27, "GET /test2.php HTTP/1.1\r\nHost: s"..., 8000) = 483
gettimeofday({1253456170, 329252}, NULL) = 0
stat64("/home/www/sandbox/htdocs/test2.php", {st_mode=S_IFREG|0644, st_size=251, ...}) = 0
writev(27, [{"HTTP/1.1 401 Authorization Requi"..., 230}, {"<!DOCTYPE HTML PUBLIC \"-//IETF//"..., 486}], 2) = 716
write(22, "10.0.1.1 - - [20/Sep/2009:23:16:"..., 82) = 82
shutdown(27, 1 /* send */)              = 0
poll([{fd=27, events=POLLIN}], 1, 2000) = 1 ([{fd=27, revents=POLLIN|POLLHUP}])
read(27, "", 512)                       = 0
close(27)                               = 0
read(8, 0xbfa94ad3, 1)                  = -1 EAGAIN (Resource temporarily unavailable)
semop(3866628, 0x4cfdb8, 1)             = 0
epoll_wait(25, {{EPOLLIN, {u32=147690928, u64=13810652316087195056}}}, 2, -1) = 1
accept(4, {sa_family=AF_INET6, sin6_port=htons(39320), inet_pton(AF_INET6, "::ffff:10.0.1.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 27
semop(3866628, 0x4cfdbe, 1)             = 0
getsockname(27, {sa_family=AF_INET6, sin6_port=htons(80), inet_pton(AF_INET6, "::ffff:10.0.1.100", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
fcntl64(27, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(27, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(27, "GET /test2.php HTTP/1.1\r\nHost: s"..., 8000) = 526
gettimeofday({1253456170, 340681}, NULL) = 0
stat64("/home/www/sandbox/htdocs/test2.php", {st_mode=S_IFREG|0644, st_size=251, ...}) = 0
open("/etc/httpd/conf/.httpasswd", O_RDONLY|O_LARGEFILE) = 28
fstat64(28, {st_mode=S_IFREG|0644, st_size=41, ...}) = 0
read(28, "dev:0VyJE\nmax:.kBjr"..., 4096) = 41
close(28)                               = 0
time(NULL)                              = 1253456170
stat64("/home/www/sandbox/config/environment.rb", 0xbfa944fc) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253456170
stat64("/home/www/sandbox/config.ru", 0xbfa944fc) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1253456170
stat64("/home/www/sandbox/passenger_wsgi.py", 0xbfa944fc) = -1 ENOENT (No such file or directory)
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
rt_sigaction(SIGPROF, {0x6aac340, [PROF], SA_RESTART}, {SIG_DFL, [], 0}, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
gettimeofday({1253456170, 343908}, NULL) = 0
getcwd("/", 4095)                       = 2
chdir("/home/www/sandbox/htdocs")       = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={30, 0}}, NULL) = 0
rt_sigaction(SIGPROF, {0x6aac340, [PROF], SA_RESTART}, {0x6aac340, [PROF], SA_RESTART}, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
time(NULL)                              = 1253456170
lstat64("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/home/www", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
lstat64("/home/www/sandbox", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
lstat64("/home/www/sandbox/htdocs", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
lstat64("/home/www/sandbox/htdocs/test2.php", {st_mode=S_IFREG|0644, st_size=251, ...}) = 0
open("/home/www/sandbox/htdocs/test2.php", O_RDONLY) = 28
fstat64(28, {st_mode=S_IFREG|0644, st_size=251, ...}) = 0
lseek(28, 0, SEEK_CUR)                  = 0
brk(0x8d64000)                          = 0x8d64000
read(28, "<?php\n\n$connect = mysql_connect("..., 8192) = 251
read(28, "", 8192)                      = 0
read(28, "", 8192)                      = 0
close(28)                               = 0
open("/etc/services", O_RDONLY)         = 28
fcntl64(28, F_GETFD)                    = 0
fcntl64(28, F_SETFD, FD_CLOEXEC)        = 0
fstat64(28, {st_mode=S_IFREG|0644, st_size=362031, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fcf000
read(28, "# /etc/services:\n# $Id: services"..., 4096) = 4096
read(28, "rotocol\nntp\t\t123/tcp\nntp\t\t123/ud"..., 4096) = 4096
read(28, "767/udp\nrsync\t\t873/tcp\t\t\t\t# rsyn"..., 4096) = 4096
read(28, "stmanager\ncvspserver\t2401/tcp\t\t\t"..., 4096) = 4096
close(28)                               = 0
munmap(0xb7fcf000, 4096)                = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTART}, {SIG_IGN, [], 0}, 8) = 0
socket(PF_FILE, SOCK_STREAM, 0)         = 28
fcntl64(28, F_SETFL, O_RDONLY)          = 0
fcntl64(28, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(28, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(28, F_SETFL, O_RDWR|O_NONBLOCK) = 0
connect(28, {sa_family=AF_FILE, path="/var/lib/mysql/mysql.sock"}, 110) = 0
fcntl64(28, F_SETFL, O_RDWR)            = 0
setsockopt(28, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
setsockopt(28, SOL_SOCKET, SO_SNDTIMEO, "\2003\341\1\0\0\0\0", 8) = 0
setsockopt(28, SOL_IP, IP_TOS, [8], 4)  = -1 EOPNOTSUPP (Operation not supported)
setsockopt(28, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
poll([{fd=28, events=POLLIN}], 1, 60000) = 1 ([{fd=28, revents=POLLIN}])
read(28, "4\0\0\0\n5.0.45\0\226\t\0\0|k%r1<yl\0,\242!\2\0\0\0"..., 16384) = 56
stat64("/usr/share/mysql/charsets/Index.xml", {st_mode=S_IFREG|0644, st_size=18173, ...}) = 0
open("/usr/share/mysql/charsets/Index.xml", O_RDONLY|O_LARGEFILE) = 29
read(29, "<?xml version='1.0' encoding=\"ut"..., 18173) = 18173
close(29)                               = 0
write(28, "<\0\0\1\205\242\0\0\0\0\0@\10\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 64) = 64
read(28, "\1\0\0\2\376", 16384)         = 5
write(28, "\t\0\0\3_ZYGFYWS\0", 13)     = 13
read(28, "\7\0\0\4\0\0\0\2\0\0\0", 16384) = 11
poll([{fd=28, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(28, "\v\0\0\0\2mt_sandbox", 15)   = 15
read(28, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11
poll([{fd=28, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(28, "\26\0\0\0\3SELECT * FROM mt_blog", 26) = 26
read(28, "\1\0\0\1A<\0\0\2\3def\nmt_sandbox\7mt_blog"..., 16384) = 6244
rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTART}, {SIG_IGN, [PIPE], SA_RESTART}, 8) = 0
poll([{fd=28, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(28, "\1\0\0\0\1", 5)              = 5
shutdown(28, 2 /* send and receive */)  = 0
close(28)                               = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTART}, {SIG_IGN, [PIPE], SA_RESTART}, 8) = 0
chdir("/")                              = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
writev(27, [{"HTTP/1.1 200 OK\r\nDate: Sun, 20 S"..., 193}, {"Array\n(\n    [0] => 1\n    [blog_i"..., 3368}], 2) = 3561
write(22, "10.0.1.1 - yoshimax [20/Sep/2009"..., 90) = 90
shutdown(27, 1 /* send */)              = 0
poll([{fd=27, events=POLLIN}], 1, 2000) = 1 ([{fd=27, revents=POLLIN|POLLHUP}])
read(27, "", 512)                       = 0
close(27)                               = 0
read(8, 0xbfa94ad3, 1)                  = -1 EAGAIN (Resource temporarily unavailable)
semop(3866628, 0x4cfdb8, 1)             = 0
epoll_wait(25,