httpd-users-de mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Stefan Bauer ...@plzk.de>
Subject Wieso 2-4 Sekunden Reaktionszeit von Apache auf HTTP GET Request
Date Fri, 22 Jan 2016 12:36:36 GMT
Hi Leute,

ich habe hier Performanceprobleme mit einer Webanwendung (langsame Reaktionszeiten 2-4 Sekunden
immer) und ich würde gerne Apache als Schuldigen ausschließen.

time curl -H "Host: our-shop-domain" http://localhost:7080/

real 0m2.295s
user 0m0.008s
sys 0m0.022s

Mit strace sehe ich die zeitliche Lücke, wo scheinbar nichts passiert. Wie ist das zu erklären?

Um 13:12:56.4 kommt der GET Request
Um 13:12:59.4 tut sich erstmal etwas.

Ich würde mich über eure Hilfe freuen.

Beste Grüße

Stefan


[pid 31765] 13:12:56.448808 read(49, "GET / HTTP/1.0\r\nHost: unique.plz"..., 8000) = 584
[pid 31765] 13:12:56.449043 stat("/var/www/vhosts/useren-shop-domain.tld/useren-shop-domain.tld/",
{st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 31765] 13:12:56.449205 open("/var/www/vhosts/.htaccess", O_RDONLY|O_CLOEXEC) = -1 ENOENT
(No such file or directory)
[pid 31765] 13:12:56.449331 lstat("/var/www/vhosts/useren-shop-domain.tld", {st_mode=S_IFDIR|0710,
st_size=4096, ...}) = 0
[pid 31765] 13:12:56.449453 open("/var/www/vhosts/useren-shop-domain.tld/.htaccess", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
[pid 31765] 13:12:56.449568 lstat("/var/www/vhosts/useren-shop-domain.tld/useren-shop-domain.tld",
{st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 31765] 13:12:56.449689 open("/var/www/vhosts/useren-shop-domain.tld/useren-shop-domain.tld/.htaccess",
O_RDONLY|O_CLOEXEC) = 50
[pid 31765] 13:12:56.449811 fstat(50, {st_mode=S_IFREG|0644, st_size=6529, ...}) = 0
[pid 31765] 13:12:56.449922 read(50, "################################"..., 4096) = 4096
[pid 31765] 13:12:56.450333 read(50, "pera mobile|palmos|webos|googleb"..., 4096) = 2433
[pid 31765] 13:12:56.450805 read(50, "", 4096) = 0
[pid 31765] 13:12:56.451002 close(50)   = 0
[pid 31765] 13:12:56.451172 stat("/var/www/vhosts/useren-shop-domain.tld/useren-shop-domain.tld/",
{st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 31765] 13:12:56.451302 stat("/var/www/vhosts/useren-shop-domain.tld/useren-shop-domain.tld/",
{st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 31765] 13:12:56.451447 stat("/var/www/vhosts/useren-shop-domain.tld/useren-shop-domain.tld/index.php",
{st_mode=S_IFREG|0644, st_size=2599, ...}) = 0
[pid 31765] 13:12:56.451602 stat("/var/www/vhosts/useren-shop-domain.tld/useren-shop-domain.tld/index.php",
{st_mode=S_IFREG|0644, st_size=2599, ...}) = 0
[pid 31765] 13:12:56.451808 fcntl(39, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31765] 13:12:56.451925 fcntl(39, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31765] 13:12:56.452037 fcntl(39, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31765] 13:12:56.452145 fcntl(39, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31765] 13:12:56.452249 fcntl(44, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31765] 13:12:56.452355 write(41, "/var/www/cgi-bin/cgi_wrapper/cgi"..., 13160) = 13160
[pid 31733] 13:12:56.452512 <... poll resumed> ) = 1 ([{fd=40, revents=POLLIN}])
[pid 31765] 13:12:56.452595 read(42,  <unfinished ...>
[pid 31733] 13:12:56.452662 read(40, "/var/www/cgi-bin/cgi_wrapper/cgi"..., 13160) = 13160
[pid 31733] 13:12:56.452811 fcntl(39, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31733] 13:12:56.452947 fcntl(39, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31733] 13:12:56.453095 unlink("/var/lib/apache2/fcgid/sock/31733.33") = -1 ENOENT (No
such file or directory)
[pid 31733] 13:12:56.453242 socket(PF_LOCAL, SOCK_STREAM, 0) = 41
[pid 31733] 13:12:56.453371 umask(077)  = 022
[pid 31733] 13:12:56.453490 bind(41, {sa_family=AF_LOCAL, sun_path="/var/lib/apache2/fcgid/sock/31733.33"},
110) = 0
[pid 31733] 13:12:56.453676 umask(022)  = 077
[pid 31733] 13:12:56.453792 chmod("/var/lib/apache2/fcgid/sock/31733.33", 0700) = 0
[pid 31733] 13:12:56.453923 listen(41, 5) = 0
[pid 31733] 13:12:56.454042 geteuid()   = 33
[pid 31733] 13:12:56.454157 fcntl(41, F_GETFD) = 0
[pid 31733] 13:12:56.454270 fcntl(41, F_SETFD, FD_CLOEXEC) = 0
[pid 31733] 13:12:56.454391 dup(2)      = 42
[pid 31733] 13:12:56.454577 fcntl(42, F_GETFD) = 0
[pid 31733] 13:12:56.454745 fcntl(42, F_SETFD, 0) = 0
[pid 31733] 13:12:56.454867 dup(2)      = 45
[pid 31733] 13:12:56.454986 fcntl(45, F_GETFD) = 0
[pid 31733] 13:12:56.455097 fcntl(45, F_SETFD, 0) = 0
[pid 31733] 13:12:56.455235 dup(41)     = 46
[pid 31733] 13:12:56.455355 fcntl(46, F_GETFD) = 0
[pid 31733] 13:12:56.455491 fcntl(46, F_SETFD, 0) = 0
[pid 31733] 13:12:56.455620 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7f8e68dfaa50) = 32162
[pid 31733] 13:12:56.457247 close(46)   = 0
[pid 31733] 13:12:56.457376 close(45)   = 0
[pid 31733] 13:12:56.457557 close(42)   = 0
[pid 31733] 13:12:56.457681 close(41)   = 0
[pid 31733] 13:12:56.457806 fcntl(39, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31733] 13:12:56.457938 fcntl(39, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31733] 13:12:56.458078 write(43, "p", 1 <unfinished ...>
[pid 31765] 13:12:56.458236 <... read resumed> "p", 1) = 1
[pid 31733] 13:12:56.458291 <... write resumed> ) = 1
[pid 31765] 13:12:56.458337 fcntl(44, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}
<unfinished ...>
[pid 31733] 13:12:56.458411 poll([{fd=40, events=POLLIN}], 1, 3000 <unfinished ...>
[pid 31765] 13:12:56.458479 <... fcntl resumed> ) = 0
[pid 31765] 13:12:56.458549 fcntl(39, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31765] 13:12:56.458672 fcntl(39, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31765] 13:12:56.458845 socket(PF_LOCAL, SOCK_STREAM, 0) = 50
[pid 31765] 13:12:56.458980 connect(50, {sa_family=AF_LOCAL, sun_path="/var/lib/apache2/fcgid/sock/31733.33"},
110) = 0
[pid 31765] 13:12:56.459119 fcntl(50, F_GETFL) = 0x2 (flags O_RDWR)
[pid 31765] 13:12:56.459233 fcntl(50, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 31765] 13:12:56.459347 writev(50, [{"\1\1\0\1\0\10\0\0", 8}, {"\0\1\0\0\0\0\0\0", 8},
{"\1\4\0\1\5\235\0\0", 8}, {"\22\0HTTP_AUTHORIZATION\0216PP_CUSTOM_"..., 1437}, {"\1\4\0\1\0\0\0\0",
8}, {"\1\5\0\1\0\0\0\0", 8}], 6) = 1477
[pid 31765] 13:12:56.459522 read(50, 0x7f8e67845048, 8192) = -1 EAGAIN (Resource temporarily
unavailable)
[pid 31765] 13:12:56.459652 poll([{fd=50, events=POLLIN}], 1, 45000 <unfinished ...>
[pid 31733] 13:12:56.465314 <... poll resumed> ) = ? ERESTART_RESTARTBLOCK (Interrupted
by signal)
[pid 31733] 13:12:56.465414 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=31985,
si_status=0, si_utime=136, si_stime=88} ---
[pid 31733] 13:12:56.465498 restart_syscall(<... resuming interrupted call ...> <unfinished
...>
[pid 31730] 13:12:56.524113 <... select resumed> ) = 0 (Timeout)
[pid 31730] 13:12:56.524218 wait4(-1, 0x7ffea19293f4, WNOHANG|WSTOPPED, NULL) = 0
[pid 31730] 13:12:56.524370 select(0, NULL, NULL, NULL, {1, 0}) = 0 (Timeout)
[pid 31730] 13:12:57.525731 wait4(-1, 0x7ffea19293f4, WNOHANG|WSTOPPED, NULL) = 0
[pid 31730] 13:12:57.525906 select(0, NULL, NULL, NULL, {1, 0}) = 0 (Timeout)
[pid 31730] 13:12:58.527241 wait4(-1, 0x7ffea19293f4, WNOHANG|WSTOPPED, NULL) = 0
[pid 31730] 13:12:58.527359 select(0, NULL, NULL, NULL, {1, 0} <unfinished ...>
[pid 31765] 13:12:59.405886 <... poll resumed> ) = 1 ([{fd=50, revents=POLLIN}])
[pid 31765] 13:12:59.406008 read(50, "\1\6\0\1\1d\4\0Expires: Thu, 19 Nov 198"..., 8192) =
8192
[pid 31765] 13:12:59.406265 read(50, "Bitte geben Sie eine g\\u00fcltig"..., 8192) = 8192
[pid 31765] 13:12:59.406399 read(50, "g-cart\"></i>\t\t\t<span>Sie haben k"...,
8192) = 8192
[pid 31765] 13:12:59.406524 read(50, "><div class=\"menu-wrapper\" colum"..., 8192)
= 8192
[pid 31765] 13:12:59.406641 read(50, "href=\"http://useren-shop-domain.tld"..., 8192) = 8192
[pid 31765] 13:12:59.406824 read(50, "\t\t\t\t\t<div class=\"slider\">\n\t\t\t\t\t\t"...,
8192) = 8192
[pid 31765] 13:12:59.406937 read(50, "    jQuery(window).on('orientati"..., 8192) = 8192
[pid 31765] 13:12:59.407048 read(50, "><span id='ajax_wishlist_loading"..., 8192) =
8192
[pid 31765] 13:12:59.407157 read(50, "t\"></i></div>\n\t\t\t\t\t\t<div class
="..., 8192) = 8192
[pid 31765] 13:12:59.407293 read(50, ": true,\n\t\t\tinfiniteSlider: false"..., 8192) = 8192
[pid 31765] 13:12:59.407401 read(50, "' style='display:none'>Test</a>\n"..., 8192)
= 8192
[pid 31765] 13:12:59.407514 read(50, "Test</a>\n\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t\t</"...,
8192) = 8192
[pid 31765] 13:12:59.407622 read(50, "pan><span class=\"shipping-cost-d"..., 8192) =
8192
[pid 31765] 13:12:59.407731 read(50, "4 omega\">\r\n\t\t<a href=\"#\" title=\""...,
8192) = 8192
[pid 31765] 13:12:59.407836 read(50, "=\"button btn-post\" title=\"weiter"..., 8192) = 8192
[pid 31765] 13:12:59.407941 read(50, "            <div class=\"ca-item-"..., 8192) = 8192
[pid 31765] 13:12:59.408051 read(50, "div>\r\n            </div>\r\n      "..., 8192)
= 8192
[pid 31765] 13:12:59.408192 brk(0x7f8e6a848000) = 0x7f8e6a848000
[pid 31765] 13:12:59.413538 writev(49, [{"HTTP/1.1 200 OK\r\nDate: Fri, 22 J"..., 516}, {"\37\213\10\0\0\0\0\0\0\3",
10}, {"\354}[w\3338\262\356\263\263\326\374\7\214zz\313\236\230\242$\337\342\304\366\214\235\373$N2\261"...,
8096}, {"\253\6\207c\221\221<\340\31\227E]\0343yYEWfY\32\305\340\232\331\314\253\244(\262\24\7"...,
5679}], 4) = 14301
[pid 31765] 13:12:59.413796 read(50, "erkonto\">Mein Benutzerkonto</a><"..., 8192)
= 4856
[pid 31765] 13:12:59.419115 writev(49, [{"\354=\333R\33I\226\317\356\210\375\207\264f\326\202\261\256\210\2331fW`\260\31\33\233\5\333\335\323"...,
8096}, {"HH\257\2d\321\240\3669\212\315\314Bd@\371\376\324\222\306pK\247)Z\6\267k}\216\34\236"...,
3253}], 2) = 11349
[pid 31765] 13:12:59.419212 read(50, 0x7f8e667fd048, 8192) = -1 EAGAIN (Resource temporarily
unavailable)
[pid 31765] 13:12:59.419294 poll([{fd=50, events=POLLIN}], 1, 45000) = 1 ([{fd=50, revents=POLLIN|POLLHUP}])
[pid 31765] 13:12:59.456599 read(50, "\1\6\0\1\0\5\3\0html>\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\000198",
8192) = 32
[pid 31765] 13:12:59.456777 close(50)   = 0
[pid 31765] 13:12:59.456926 fcntl(39, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31765] 13:12:59.457059 fcntl(39, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0})
= 0
[pid 31765] 13:12:59.457219 brk(0x7f8e6a808000) = 0x7f8e6a808000
[pid 31765] 13:12:59.457408 writev(49, [{"\313(\311\315\261\3\0", 7}, {"\252\275\267\7u1\2\0",
8}], 2) = 15
[pid 31765] 13:12:59.457653 write(22, "2003:62:4a5b:2700:544a:4c62:7311"..., 216) = 216
[pid 31765] 13:12:59.457813 times({tms_utime=10, tms_stime=4, tms_cutime=0, tms_cstime=0})
= 2232326703
[pid 31765] 13:12:59.457942 shutdown(49, SHUT_WR) = 0
[pid 31765] 13:12:59.458075 poll([{fd=49, events=POLLIN}], 1, 2000) = 1 ([{fd=49, revents=POLLIN|POLLHUP}])
[pid 31765] 13:12:59.458188 read(49, "", 512) = 0
[pid 31765] 13:12:59.458294 close(49)   = 0
[pid 31765] 13:12:59.458411 read(8, 0x7ffea1929347, 1) = -1 EAGAIN (Resource temporarily unavailable)
[pid 31765] 13:12:59.458524 fcntl(47, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}
<unfinished ...>
[pid 31733] 13:12:59.461588 <... restart_syscall resumed> ) = 0
[pid 31733] 13:12:59.461661 poll([{fd=40, events=POLLIN}], 1, 3000 <unfinished ...>
[pid 31739] 13:12:59.488870 <... epoll_wait resumed> {{EPOLLIN, {u32=1756586736, u64=140249618670320}}},
2, 10000) = 1
[pid 31739] 13:12:59.488965 accept4(5, {sa_family=AF_INET6, sin6_port=htons(39025), inet_pton(AF_INET6,
"server-v6-addresse", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28], SOCK_CLOEXEC)
= 49
[pid 31739] 13:12:59.489186 fcntl(47, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}
<unfinished ...>
[pid 31746] 13:12:59.489323 <... fcntl resumed> ) = 0
[pid 31739] 13:12:59.489359 <... fcntl resumed> ) = 0
[pid 31746] 13:12:59.489418 epoll_wait(48,  <unfinished ...>
[pid 31739] 13:12:59.489472 getsockname(49, {sa_family=AF_INET6, sin6_port=htons(7080), inet_pton(AF_INET6,
"server-v6-addresse", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
[pid 31739] 13:12:59.489618 fcntl(49, F_GETFL) = 0x2 (flags O_RDWR)
[pid 31739] 13:12:59.489727 fcntl(49, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 31739] 13:12:59.489854 read(49, "GET /media/css/753d75e7ed04e7211"..., 8000) = 585
[pid 31739] 13:12:59.490083 stat("/var/www/vhosts/useren-shop-domain.tld/useren-shop-domain.tld/media/css/753d75e7ed04e721120a02d7ba91647f.css",
{st_mode=S_IFREG|0666, st_size=541450, ...}) =


---------------------------------------------------------------------
To unsubscribe, e-mail: users-de-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-de-help@httpd.apache.org


Mime
View raw message