Лак 503 ничего не содержит в журнале Apache

#apache #magento2 #varnish

#apache #magento2 #лак

Вопрос:

Мы получаем случайные 503 ответа от Varnish, и при более глубоком изучении журнала varnishlog мы видим, что внутренний сервер (Apache) сообщается как 503, но в журнале доступа apache ничего нет.

Как мы можем отследить причину этой проблемы?

Из журнала varnishlog

 *   << Request  >> 42221068  
-   Begin          req 42221065 rxreq
-   Timestamp      Start: 1553163507.132639 0.000000 0.000000
-   Timestamp      Req: 1553163507.132639 0.000000 0.000000
-   ReqStart       172.31.19.159 14390
-   ReqMethod      POST
-   ReqURL         /path/to/request
-   ReqProtocol    HTTP/1.1
-   ReqHeader      X-Forwarded-For: 62.103.214.39
-   ReqHeader      X-Forwarded-Proto: https
-   ReqHeader      X-Forwarded-Port: 443
-   ReqHeader      Host: server.com
-   ReqHeader      X-Amzn-Trace-Id: Root=1-5c9364f3-26a603e3ce2f87d9923ed27e
-   ReqHeader      Content-Length: 53
-   ReqHeader      Accept: application/json
-   ReqHeader      Authorization: Bearer xxx
-   ReqHeader      Content-Type: application/json; charset=utf-8
-   ReqHeader      Cookie: PHPSESSID=o1f3010cuch8iu055stl6q1s03
-   ReqUnset       X-Forwarded-For: 62.103.214.39
-   ReqHeader      X-Forwarded-For: 62.103.214.39, 172.31.19.159
-   VCL_call       RECV
-   VCL_return     pass
-   VCL_call       HASH
-   VCL_return     lookup
-   VCL_call       PASS
-   VCL_return     fetch
-   Link           bereq 42221069 pass
-   Storage        malloc Transient
-   Timestamp      ReqBody: 1553163507.952175 0.819536 0.819536
-   Timestamp      Fetch: 1553163507.952297 0.819659 0.000123
-   RespProtocol   HTTP/1.1
-   RespStatus     503
-   RespReason     Backend fetch failed
-   RespHeader     Date: Thu, 21 Mar 2019 10:18:27 GMT
-   RespHeader     Server: Varnish
-   RespHeader     Content-Type: text/html; charset=utf-8
-   RespHeader     Retry-After: 5
-   RespHeader     X-Varnish: 42221068
-   RespHeader     Age: 0
-   RespHeader     Via: 1.1 varnish (Varnish/5.2)
-   VCL_call       DELIVER
-   RespUnset      Age: 0
-   RespUnset      Server: Varnish
-   RespUnset      X-Varnish: 42221068
-   RespUnset      Via: 1.1 varnish (Varnish/5.2)
-   VCL_return     deliver
-   Timestamp      Process: 1553163507.952322 0.819683 0.000024
-   RespHeader     Content-Length: 285
-   RespHeader     Connection: keep-alive
-   Timestamp      Resp: 1553163507.952341 0.819703 0.000020
-   ReqAcct        415 53 468 194 285 479
-   End            
**  << BeReq    >> 42221069  
--  Begin          bereq 42221068 pass
--  Timestamp      Start: 1553163507.132720 0.000000 0.000000
--  BereqMethod    POST
--  BereqURL       /path/to/request
--  BereqProtocol  HTTP/1.1
--  BereqHeader    X-Forwarded-Proto: https
--  BereqHeader    X-Forwarded-Port: 443
--  BereqHeader    Host: server.com
--  BereqHeader    X-Amzn-Trace-Id: Root=1-5c9364f3-26a603e3ce2f87d9923ed27e
--  BereqHeader    Content-Length: 53
--  BereqHeader    Accept: application/json
--  BereqHeader    Authorization: Bearer 3pa8ot18dlmpad2s34a5gt3p08jg0ml5
--  BereqHeader    Content-Type: application/json; charset=utf-8
--  BereqHeader    Cookie: PHPSESSID=o1f3010cuch8iu055stl6q1s03
--  BereqHeader    X-Forwarded-For: 62.103.214.39, 172.31.19.159
--  BereqHeader    X-Varnish: 42221069
--  VCL_call       BACKEND_FETCH
--  VCL_return     fetch
--  BackendOpen    32 reload_20190304_175528_18074.live1 172.31.11.111 8081 172.31.31.198 39914
--  BackendStart   172.31.11.111 8081
--  Timestamp      Bereq: 1553163507.952205 0.819485 0.819485
--  FetchError     HTC status -1
--  BackendClose   32 reload_20190304_175528_18074.live1
--  Timestamp      Beresp: 1553163507.952235 0.819514 0.000029
--  Timestamp      Error: 1553163507.952237 0.819517 0.000003
--  BerespProtocol HTTP/1.1
--  BerespStatus   503
--  BerespReason   Service Unavailable
--  BerespReason   Backend fetch failed
--  BerespHeader   Date: Thu, 21 Mar 2019 10:18:27 GMT
--  BerespHeader   Server: Varnish
--  VCL_call       BACKEND_ERROR
--  BerespHeader   Content-Type: text/html; charset=utf-8
--  BerespHeader   Retry-After: 5
--  VCL_return     deliver
--  Storage        malloc Transient
--  ObjProtocol    HTTP/1.1
--  ObjStatus      503
--  ObjReason      Backend fetch failed
--  ObjHeader      Date: Thu, 21 Mar 2019 10:18:27 GMT
--  ObjHeader      Server: Varnish
--  ObjHeader      Content-Type: text/html; charset=utf-8
--  ObjHeader      Retry-After: 5
--  Length         285
--  BereqAcct      451 53 504 0 0 0
--  End       
  

Насколько мы понимаем, Varnish сообщает о закрытом соединении (EOF) от Apache, но опять же Apache ничего не сообщает на своей стороне.

Нам нужно как-то разобраться в этом, поскольку это влияет на соглашение об обслуживании.

Есть идеи по отслеживанию и решению проблемы?

Ответ №1:

У вас нет журнала доступа Apache, потому что запрос не полностью обработан Apache, поскольку ранее была проблема.

Такого рода проблемы могут привести к этой ситуации:

  • проблема с сетью
  • Ошибка Apache, например, слишком много запросов, неверный запрос или какая-то внутренняя ошибка
  • Системная ошибка, например, слишком много открытых файлов для пользователя Apache

Где вы можете искать следы:

  • Журнал ошибок Apache
  • Журнал системных ошибок
  • Запустите tcpdump (tshark / wireshark — хорошие инструменты для этого) и найдите ошибки