время в логах на приличной нагрузке.

[calculator at land.ru]

Igor Sysoev пишет:
> On Tue, Sep 09, 2008 at 05:30:22PM +0400, calculator at land.ru wrote:
>
>   
>> Igor Sysoev пишет:
>>     
>>> On Tue, Sep 09, 2008 at 01:28:41PM +0400, calculator at land.ru wrote:
>>>
>>>  
>>>       
>>>> Igor Sysoev пишет:
>>>>    
>>>>         
>>>>> On Tue, Sep 09, 2008 at 12:44:21PM +0400, calculator at land.ru wrote:
>>>>>
>>>>>
>>>>>      
>>>>>           
>>>>>> Igor Sysoev пишет:
>>>>>>   
>>>>>>        
>>>>>>             
>>>>>>> On Tue, Sep 09, 2008 at 11:18:33AM +0400, calculator at land.ru wrote:
>>>>>>>
>>>>>>>
>>>>>>>     
>>>>>>>          
>>>>>>>               
>>>>>>>> Igor Sysoev пишет:
>>>>>>>>  
>>>>>>>>       
>>>>>>>>            
>>>>>>>>                 
>>>>>>>>> On Mon, Sep 08, 2008 at 07:11:59PM +0400, calculator at land.ru wrote:
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>    
>>>>>>>>>         
>>>>>>>>>              
>>>>>>>>>                   
>>>>>>>>>> Наблюдаю интересную картину на Linux серверах с nginx на борту 
>>>>>>>>>> которые отдают ~10k/s empty_gif и пишут лог кто когда забрал.
>>>>>>>>>> Но вот в логе(если перелопатить его пару тонн) встречаются 
>>>>>>>>>> интересные unixtime, которые явно _не к месту_. К примеру:
>>>>>>>>>>
>>>>>>>>>> 1220880388504
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220880388496
>>>>>>>>>> 1220880388496
>>>>>>>>>> 1220880388496
>>>>>>>>>> 1220880388496
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220884786554
>>>>>>>>>> 1220880388496
>>>>>>>>>>
>>>>>>>>>> Если по человечески то разница получается более часа.
>>>>>>>>>> Есть предположение что это может быть связано с linux threads 
>>>>>>>>>> потому как на нескольких серверах под FreeBSD такого не 
>>>>>>>>>> наблюдалось(хотя нагрузка на них не большая).
>>>>>>>>>> На серверах nginx 5 ветки работает.
>>>>>>>>>> Что касается загрузки самих серверов, то они сечас нагружены на 
>>>>>>>>>> ~20% от максимума что показали на тестировании.
>>>>>>>>>> Есть идеи?
>>>>>>>>>>
>>>>>>>>>>      
>>>>>>>>>>           
>>>>>>>>>>                
>>>>>>>>>>                     
>>>>>>>>> А чем пишете ? nginx так не умеет. У него было бы
>>>>>>>>> 1220884786.554
>>>>>>>>> 1220880388.496
>>>>>>>>>
>>>>>>>>>    
>>>>>>>>>         
>>>>>>>>>              
>>>>>>>>>                   
>>>>>>>> Да там модуль постобработку делает. Извиняюсь что не упомянул, но в 
>>>>>>>> общем случае он порядок не меняет.
>>>>>>>> Что интересно _пляски_ начинаются стабильно от ~8k запросов.
>>>>>>>> Увеличение NGX_TIME_SLOTS может помочь?
>>>>>>>>  
>>>>>>>>       
>>>>>>>>            
>>>>>>>>                 
>>>>>>> Во-первых, поддержка трэдов на данный момент в nginx'е сломана - может
>>>>>>> быть всё, что угодно. Во-вторых, я в данном случае вообще не понимаю,
>>>>>>> что именно логируется.
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>     
>>>>>>>          
>>>>>>>               
>>>>>> Ага, исправлюсь. Вот формат логов.
>>>>>>
>>>>>>  log_format  counter  '$request_uri  $msec   $http_referer   
>>>>>> $remote_addr'
>>>>>>                      '       $http_user_agent        
>>>>>> $http_accept_language'
>>>>>>                      '       $http_x_forwarded_for'
>>>>>>                      '       $counter_uid';
>>>>>>  access_log  logs/access.log  counter;
>>>>>>
>>>>>>
>>>>>> После обработки примерно такие логи получаются:
>>>>>>
>>>>>> /two****request_uri     1220880388504   http_referer    78.107.87.211   
>>>>>> Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; MRSPUTNIK 2, 0, 0, 
>>>>>> 36 SW; .NET CLR 1.1.4322; InfoPath.1)     ru      -       
>>>>>> B0B903034799DD57:1201266007
>>>>>> /two***request_uri      1220884786554   -       81.24.208.13    
>>>>>> Mozilla/5.0 (Windows; U; Windows NT 5.1; ru; rv:1.8.1.16) 
>>>>>> Gecko/20080702 Firefox/2.0.0.16 WebMoney Advisor      
>>>>>> ru-ru,ru;q=0.8,en-us;q=0.5,en;q=0.3     -       -
>>>>>> /two****request_uri     1220880388496   http_referer    78.132.162.209  
>>>>>> Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; MRA 5.0 (build 
>>>>>> 02094))       ru      -       E5930201476FE72C:1198516012
>>>>>>   
>>>>>>        
>>>>>>             
>>>>> Правильно ли я понимаю, что используется стандартный nginx без каких-либо
>>>>> дополнительных изменений и из логах в $msec потом просто убирается точка 
>>>>> ?
>>>>>
>>>>>
>>>>>      
>>>>>           
>>>> Да, именно так.
>>>>    
>>>>         
>>> А можно ещё писать в лог номер процесса, чтобы посмотреть, где идёт
>>> отставание ?
>>>  
>>>       
>> Да в том то и дело что нет. На боевом сервере формат логов оговорен, мы 
>> их отдаем на обработку потом. Если поднапрячься наверно можно 2 сервера 
>> еще собрать на тестирование но нужно будет еще код counter'а подправить.
>> Еще заметили закономерность что разница во времени всегда 4398 либо 4399
>>     
>
> Можно завести параллельно второй лог.
>
>
>   
Да, похоже во время больших нагрузок так и сделаем.
Но похоже нам придется немного код nginx'а дополнить чтобы pid в логи 
писать или я ошибаюсь?