ПРОЕКТЫ 


  АРХИВ 


Apache-Talk @lexa.ru 

Inet-Admins @info.east.ru 

Filmscanners @halftone.co.uk 

Security-alerts @yandex-team.ru 

nginx-ru @sysoev.ru 


  СТАТЬИ 


  ПЕРСОНАЛЬНОЕ 


  ПРОГРАММЫ 



ПИШИТЕ
ПИСЬМА












     АРХИВ :: nginx-ru
Nginx-ru mailing list archive (nginx-ru@sysoev.ru)

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: worker process exited on signal 11 (core dumped)



Hello!

On Fri, Feb 19, 2010 at 07:41:07PM +0300, Igor Sysoev wrote:

> On Tue, Feb 16, 2010 at 02:54:29PM +0300, Maxim Dounin wrote:
> 
> > Hello!
> > 
> > On Wed, Feb 10, 2010 at 09:42:47PM +0300, Vladimir Sopot wrote:
> > 
> > > 
> > > On Feb 10, 2010, at 3:49 PM, Maxim Dounin wrote:
> > > 
> > > >>> Ok, кажется я понял проблему.  Судя по всему memcached_pass не 
> > > >>> дожидается полного прилёта trailer'а ("END") и ругается.  А в 
> > > >>> случае keepalive остатки trailer'а долетают в ответ на следующий 
> > > >>> запрос.
> > > >>> 
> > > >>> По идее строка "invalid trailer" должна наблюдаться и без 
> > > >>> keepalive (но скорее всего реже), а "invalid response" - только 
> > > >>> если keepalive включён.
> > > >> 
> > > >> 50 минут - полет нормальный, 
> > > >> 
> > > >> # grep -c 'subrequests cycle while processing' error.log
> > > >> 22076
> > > >> # grep memcached error.log
> > > >> #
> > > > 
> > > > Видимо "реже" в данном случае вырождается в "почти никогда".
> > > 
> > > Однако, все же "почти" никогда:
> > > 
> > > # sed -n "1 p" error.log 
> > > 2010/02/10 16:08:53 [error] 14875#0: *282680 directory index of 
> > > "/wwwroot/" is forbidden
> > > # grep memcached error.log
> > > 2010/02/10 19:13:00 [error] 7643#0: *9676423 memcached sent invalid 
> > > trailer while sending to client
> > > 2010/02/10 19:40:46 [error] 7638#0: *11190967 memcached sent invalid 
> > > trailer while sending to client
> > > 2010/02/10 19:44:17 [error] 7641#0: *11386082 memcached sent invalid 
> > > trailer while sending to client
> > > 2010/02/10 19:50:40 [error] 7646#0: *11737608 memcached sent invalid 
> > > trailer while sending to client
> > > 2010/02/10 20:31:27 [error] 14006#0: *13901259 memcached sent invalid 
> > > trailer while sending to client
> > > 2010/02/10 21:28:42 [error] 20249#0: *16943253 memcached sent invalid 
> > > trailer while sending to client
> > 
> > Патч.
> > 
> > Maxim Dounin
> 
> > # HG changeset patch
> > # User Maxim Dounin <mdounin@xxxxxxxxxx>
> > # Date 1266320928 -10800
> > # Node ID 9009f1982e02d6f0614d4ddeae0672042442775a
> > # Parent  09972a4975970f7c3510177b8a287283d3a53c58
> > Memcached: correctly handle trailer split into several packets.
> > 
> > With old code message "[error] ... memcached sent invalid trailer" may 
> > appear
> > in logs for no reason.  It doesn't cause any harm except message itself
> > with official nginx though may cause spurious errors on connection reuse 
> > with
> > upstream keepalive module.
> > 
> > diff --git a/src/http/modules/ngx_http_memcached_module.c 
> > b/src/http/modules/ngx_http_memcached_module.c
> > --- a/src/http/modules/ngx_http_memcached_module.c
> > +++ b/src/http/modules/ngx_http_memcached_module.c
> > @@ -432,15 +432,20 @@ ngx_http_memcached_filter(void *data, ss
> >  
> >          if (ngx_strncmp(b->last,
> >                     ngx_http_memcached_end + NGX_HTTP_MEMCACHED_END - 
> > ctx->rest,
> > -                   ctx->rest)
> > +                   bytes)
> >              != 0)
> >          {
> >              ngx_log_error(NGX_LOG_ERR, ctx->request->connection->log, 0,
> >                            "memcached sent invalid trailer");
> > +
> > +            u->length = 0;
> > +            ctx->rest = 0;
> > +
> > +            return NGX_OK;
> >          }
> >  
> > -        u->length = 0;
> > -        ctx->rest = 0;
> > +        u->length -= bytes;
> > +        ctx->rest -= bytes;
> >  
> >          return NGX_OK;
> >      }
> 
> Макс, до 0.6.14 был практический такой же код, который ты привёл.
> Commit message: "fix memcached END test"

Угу, вижу:

    *) Bugfix: a worker process may got caught in an endless loop, if the 
       memcached was used.

К сожалению этой проблемой занимался не я, и тестов я так понимаю 
на неё нет... ;) Ниже разбор по коду что это было.

> Index: src/http/modules/ngx_http_memcached_module.c
> ===================================================================
> --- src/http/modules/ngx_http_memcached_module.c      (revision 873)
> +++ src/http/modules/ngx_http_memcached_module.c      (revision 874)
> @@ -426,15 +426,15 @@
>  
>          if (ngx_strncmp(b->last,
>                     ngx_http_memcached_end + NGX_HTTP_MEMCACHED_END - 
> ctx->rest,
> -                   bytes)
> +                   ctx->rest)
>              != 0)
>          {
>              ngx_log_error(NGX_LOG_ERR, ctx->request->connection->log, 0,
>                            "memcached sent invalid trailer");
>          }
>  
> -        u->length -= bytes;
> -        ctx->rest -= bytes;
> +        u->length = 0;
> +        ctx->rest = 0;

Вот тут - не было выхода по ошибке вообще, а стал безусловный 
выход в том числе из-за недочитанности ответа.

>  
>          return NGX_OK;
>      }
> @@ -453,7 +453,8 @@
>  
>      *ll = cl;
>  
> -    cl->buf->pos = b->last;
> +    last = b->last;
> +    cl->buf->pos = last;
>      b->last += bytes;
>      cl->buf->last = b->last;
>  
> @@ -461,20 +462,19 @@
>                     "memcached filter bytes:%z size:%z length:%z rest:%z",
>                     bytes, b->last - b->pos, u->length, ctx->rest);
>  
> -    if (b->last - b->pos <= (ssize_t) (u->length - NGX_HTTP_MEMCACHED_END)) {
> +    if (bytes <= (ssize_t) (u->length - NGX_HTTP_MEMCACHED_END)) {

В старом коде проверялось "b->last - b->pos" - т.е. сколько лежит 
в буфере.  В новом проверяется bytes - т.е. сколько байт принято в 
этом вызове фильтра.

Поскольку u->length имеет смысл только для этого вызова фильтра - 
проверять надо bytes (i.e. в новом коде правильно).  В старом коде 
прочитанная половина ответа могла привести к решению "мы уже всё 
прочитали, надо парсить END".

>          u->length -= bytes;
>          return NGX_OK;
>      }
>  
> +    last += u->length - NGX_HTTP_MEMCACHED_END;
>  
> -    last = b->pos + u->length - NGX_HTTP_MEMCACHED_END;
> -
>      if (ngx_strncmp(last, ngx_http_memcached_end, b->last - last) != 0) {
>          ngx_log_error(NGX_LOG_ERR, ctx->request->connection->log, 0,
>                        "memcached sent invalid trailer");
>      }
>  
> -    ctx->rest = u->length - (b->last - b->pos);
> +    ctx->rest -= b->last - last;

А вот тут в старом коде дополнительный сюрприз: если в буфере уже 
лежит больше чем u->length, то ctx->rest станет отрицательным.  А 
он size_t, т.е. станет он большим положительным.

>      b->last = last;
>      cl->buf->last = last;
>      u->length = ctx->rest;

Ну и тут u->length ставится из большого отрицательного ctx->rest, 
что приводит к вечноживущему соединению с memcached.

И при этом, как мы помним, выхода по ошибкам сравнения с END - не 
предусмотрено.

Бесконечного цикла я тут всё равно не вижу, но IMHO и того что 
видно - хватает за глаза.  Намусорить в error log на больших 
ответах оно могло прилично.

В тестах на 0.6.13 я ругань воспроизвести могу (при использовании 
ssi include set="" и инструментированного бекенда).  На 0.8.33 с 
патчем та же проблема не воспроизводится (и не должна).

Тест вот тут:

http://mdounin.ru/hg/nginx-tests/rev/25047dc6ae9b

Maxim Dounin

_______________________________________________
nginx-ru mailing list
nginx-ru@xxxxxxxxx
http://nginx.org/mailman/listinfo/nginx-ru


 




Copyright © Lexa Software, 1996-2009.