Рантайм одного и того же скрипта отличается в сотни раз

Вот такое интересное дело наблюдается. Добавил к морде одного из ресурсов (index.php) лог времени выполнения. Время выполнения одного и того же скрипта у разных пользователей отличается в сотни раз - у одного может быть 0.055 секунд, у другого 4.991. Как такое может быть? Кусок лога:

Код:

[2010-05-06 22:45:02] (XX.93.32.26) index.php 2.332 [2010-05-06 22:45:15] (XX.54.199.93) index.php 3.130 [2010-05-06 22:45:18] (XX.93.32.26) index.php 2.696 [2010-05-06 22:45:33] (XX.120.128.110) index.php 4.991 [2010-05-06 22:45:36] (XX.34.134.247) index.php 2.314 [2010-05-06 22:45:39] (XX.22.184.52) index.php 0.255 [2010-05-06 22:45:41] (XX.168.178.56) index.php 3.340 [2010-05-06 22:45:42] (XX.246.127.80) index.php 0.054 [2010-05-06 22:45:58] (XX.73.111.87) index.php 3.813 [2010-05-06 22:46:01] (XX.73.111.87) index.php 2.289 [2010-05-06 22:46:06] (XX.93.32.26) index.php 2.186 [2010-05-06 22:46:14] (XX.149.66.125) index.php 2.208 [2010-05-06 22:46:25] (XX.55.50.90) index.php 0.055 [2010-05-06 22:46:26] (XX.54.199.93) index.php 2.268 [2010-05-06 22:46:47] (XX.73.111.87) index.php 3.506 [2010-05-06 22:46:53] (XX.106.196.119) index.php 0.052 [2010-05-06 22:47:00] (XX.22.184.52) index.php 0.052 [2010-05-06 22:47:07] (XX.135.119.38) index.php 2.246

Причём например, у меня, тайминги похожие, и составляют в среднем 2.3 сек:

Код:

[2010-05-06 22:45:02] (XX.93.32.26) index.php 2.332 [2010-05-06 22:45:18] (XX.93.32.26) index.php 2.696 [2010-05-06 22:46:06] (XX.93.32.26) index.php 2.186 [2010-05-06 22:49:18] (XX.93.32.26) index.php 2.212

А у другого юзера, наоборот, около 0.055 сек:

Код:

[2010-05-06 22:46:25] (XX.55.50.90) index.php 0.055 [2010-05-06 22:55:21] (XX.55.50.90) index.php 0.055 [2010-05-06 22:59:45] (XX.55.50.90) index.php 0.056 [2010-05-06 23:13:07] (XX.55.50.90) index.php 0.052

Да, контент у разных юзеров на морде разный (через GeoIP), но из одной и той же базы. В чём может быть причина?

так надо смотреть что скрипт делает. может там что-то с другого сервера запрашивается в процессе выполнения, да мало ли что. тем более если ты говоришь что на геоип завязано, то скорее всего для одной страны выполняются какие то действия, которые не выполняются для другой, или они выполняются быстрее, что может быть связано с объемом данных в базе, например.

А может связано с нагрузкой на сервак в момент времени?

X777 писал:

А может связано с нагрузкой на сервак в момент времени?

Я думал, что это наиболее вероятная причина. Сервак-то нагруженный по самое немогу. Но потом добавил в статистику loadavg, и вот результат (time|ip|script|runtime|loadavg):

Код:

2010-05-07 7:24:40|XX.21.24.86|index.php| 4.204|1.279 2010-05-07 7:24:54|XX.61.60.50|index.php| 2.500|1.377 2010-05-07 7:24:55|XX.55.50.90|index.php| 0.050|1.377 2010-05-07 7:28:39|XX.18.248.2|index.php| 0.052|1.633 2010-05-07 7:25:19|XX.93.32.26|index.php|13.546|1.435

Причина похоже, не связана с GEO, т.к для одной и той же страны время выполнения различается очень сильно:

Код:

2010-05-07 7:24:40|XX.217.244.86 |index.php| 4.204|1.279 Australia Perth Telstra Internet 2010-05-07 7:24:54|XX.61.60.50   |index.php| 2.500|1.377 United States Dublin Road Runner Holdco Llc 2010-05-07 7:24:55|XX.55.50.90   |index.php| 0.050|1.377 United States Brooklyn Reality Check Network Corp 2010-05-07 7:24:56|XX.108.253.92 |index.php| 0.053|1.377 Norway Bergen Telenor Business Solution As 2010-05-07 7:25:07|XX.130.28.106 |index.php| 3.070|1.473 Bangladesh Dhaka Zx Online Ltd. Isp Of Bangladesh 2010-05-07 7:25:15|XX.130.28.106 |index.php| 5.945|1.473 Bangladesh Dhaka Zx Online Ltd. Isp Of Bangladesh 2010-05-07 7:25:19|XX.93.32.26   |index.php|13.546|1.435 Ukraine Seech-infocom 1st Net 2010-05-07 7:25:28|XX.108.253.92 |index.php| 0.053|1.400 Norway Bergen Telenor Business Solution As 2010-05-07 7:25:30|XX.149.66.125 |index.php|15.479|1.368 United States Kennebunk Private Customer - Helicon Cable - Redwood 2010-05-07 7:25:47|XX.149.66.125 |index.php| 2.270|1.286 United States Kennebunk Private Customer - Helicon Cable - Redwood 2010-05-07 7:25:50|XX.220.68.1   |index.php| 0.052|1.263 Nigeria Lagos Afrinic 2010-05-07 7:26:12|XX.76.68.228  |index.php| 3.165|1.347 Ireland Dublin Vodafone Isp 2010-05-07 7:26:16|XX.125.66.75  |index.php| 0.055|1.319 China Beijing China Unicom Beijing Province Network 2010-05-07 7:26:22|XX.181.7.96   |index.php| 0.052|1.293 China Beijing Chinanet Beijing Province Network 2010-05-07 7:26:26|XX.123.40.80  |index.php| 2.366|1.270 Romania Craiova Rcs & Rds S.a 2010-05-07 7:26:34|XX.154.68.28  |index.php| 0.194|1.228 Poland Warsaw Adsl Network (dynamic Ip Pool) 2010-05-07 7:26:52|XX.199.146.215|index.php| 2.236|3.615 United States Yorktown Verizon Internet Services Inc 2010-05-07 7:26:56|XX.83.159.142 |index.php| 0.101|3.406 Japan Tokyo Internet Content Provider 2010-05-07 7:27:07|XX.136.9.49   |index.php| 0.054|2.873 United States Machesney Park Comcast Cable Communications Inc 2010-05-07 7:27:22|XX.170.3.185  |index.php| 0.059|2.661 United States Las Vegas Cox Communications

это может быть связано с тем что медленное соединение у клиентов и они долго ответ получают , ты по моему не правильно сделал

надо делать тайминг каждого куска скрипта , тогда ты поймешь в чем проблема , а так гадание на кофейной гуще

leroy_17 писал:

это может быть связано с тем что медленное соединение у клиентов и они долго ответ получают , ты по моему не правильно сделал

так, а считается-то время выполнения скрипта сервером, а не задержка между отправкой запроса и получением клиентом ответа. т.е клиент отправил запрос, скрипт на сервере запустился, вот его время выполнения и считается.

leroy_17 писал:

надо делать тайминг каждого куска скрипта , тогда ты поймешь в чем проблема , а так гадание на кофейной гуще

да, следующим шагом как раз будет именно выявление наиболее ресурсоемких частей.

alex.raven писал:

так, а считается-то время выполнения скрипта сервером, а не задержка между отправкой запроса и получением клиентом ответа. т.е клиент отправил запрос, скрипт на сервере запустился, вот его время выполнения и считается.

Верно, если у тебя скрипт не выполняет разный набор функций в зависимости от гео, то скорость его выполнения никак не зависит от географического положения посетителя.

alex.raven писал:

да, следующим шагом как раз будет именно выявление наиболее ресурсоемких частей.

Если нароеш функцию, которая выдаст сколько скрипт (на php) жрет памяти во время своего исполнения будет

X777 писал:

Если нароеш функцию, которая выдаст сколько скрипт (на php) жрет памяти во время своего исполнения будет

вобщето это стандартная функция php , называется чето типа memory_get_usage

X777 писал:

Верно, если у тебя скрипт не выполняет разный набор функций в зависимости от гео, то скорость его выполнения никак не зависит от географического положения посетителя.

да, набор функций один и тот же, отличается только выборка из базы, которая зависит от гео.

X777 писал:

Если нароеш функцию, которая выдаст сколько скрипт (на php) жрет памяти во время своего исполнения будет

это было бы актуально, если б перерасход памяти шёл и свопилось бы постоянно, а так из 4 гб оперативки на серваке обычно ещё около 1 гб свободной.

Еще может такая штука быть, как рэндомная чистка кэша. Или просто кэш устревает и страница генерируется заново, отсюда и время.

Раз к базе обращается - можно быть уверенным, что там и разница. Включай лог медленных запросов в mysql и смотри. mtop, опять же. А так - гадание на кофейной гуще, "по какой причине из тысяч возможных программа может медленнее отрабатывать".