Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

EDIT1 : I tried the setting suggested on my preprod environment without success. Since I can reproduce the issue on another environment I tried to look for similarities.

I disabled logrotate for varnish without positive results. The only common point is the cron.hourly. Which is empty.

This is what I have in /var/log/cron

Feb  3 14:01:01 SPRX0032 CROND[32006]: (root) CMD (run-parts /etc/cron.hourly)
Feb  3 14:01:01 SPRX0032 run-parts(/etc/cron.hourly)[32006]: starting 0anacron
Feb  3 14:01:01 SPRX0032 run-parts(/etc/cron.hourly)[32020]: finished 0anacron

And at the exact same moment my probes :

03-02-14_14:01:01 - - -  /!\ WARNING /!\|HTTP code 503| website1 SERVER IS DOWN booh! /!\ WARNING /!\
03-02-14_14:01:01 - - -  /!\ WARNING /!\|HTTP code 503| website2 SERVER IS DOWN booh! /!\ WARNING /!\
03-02-14_14:01:01 - - -  /!\ WARNING /!\|HTTP code 503| website3 SERVER IS DOWN booh! /!\ WARNING /!\
03-02-14_14:01:01 - - -  /!\ WARNING /!\|HTTP code 503| website4 SERVER IS DOWN booh! /!\ WARNING /!\

Original post:

I have a 2 Varnish (3.0.4) cluster with failover director in front of 3 Apache (2.2.15) and I encounter sporadic 503 error. This happen totally randomly, on many pages and last a minute or less. To find the culprit I set 3 probes that consist of a curl script to get the pages HTTP status code every minutes. My probes are set to fetch the page from :

  • a personnal connection.
  • the LAN hitting Varnish.
  • the LAN hitting Apache.

The one requesting Apache is free from error. Both probes from outside and the one hitting Varnish raise errors.

    29-01-14_06:17:01 - - - |HTTP code 200||response time:0.254|website1 is UP woot!
    29-01-14_06:17:02 - - - |HTTP code 200||response time:0.264|website2 is UP woot!
    29-01-14_06:17:02 - - - |HTTP code 200||response time:0.477|website3 is UP woot!
    29-01-14_06:17:03 - - - |HTTP code 200||response time:0.283|website4 is UP woot!
    29-01-14_06:17:04 - - - |HTTP code 200||response time:0.782|website5 is UP woot!
    29-01-14_06:18:28 - - - |HTTP code 200||response time:0.167|website1 is UP woot!
    29-01-14_06:18:28 - - -  /!\ WARNING /!\|HTTP code 503| website2 SERVER IS DOWN booh! /!\ WARNING /!\
    29-01-14_06:18:28 - - -  /!\ WARNING /!\|HTTP code 503| website3 SERVER IS DOWN booh! /!\ WARNING /!\
    29-01-14_06:18:29 - - -  /!\ WARNING /!\|HTTP code 503| website4 SERVER IS DOWN booh! /!\ WARNING /!\
    29-01-14_06:18:29 - - -  /!\ WARNING /!\|HTTP code 503| website5 SERVER IS DOWN booh! /!\ WARNING /!\
    29-01-14_06:19:01 - - - |HTTP code 200||response time:0.243|website1 is UP woot!
    29-01-14_06:19:02 - - - |HTTP code 200||response time:0.313|website2 is UP woot!
    29-01-14_06:19:03 - - - |HTTP code 200||response time:0.552|website3 is UP woot!
    29-01-14_06:19:03 - - - |HTTP code 200||response time:0.348|website4 is UP woot!
    29-01-14_06:19:05 - - - |HTTP code 200||response time:0.704|website5 is UP woot!

Here are my backends

backend srv1 {
        .host = "srv1";
        .port = "80";
        .first_byte_timeout = 300s;
        .connect_timeout = 5s;
        .between_bytes_timeout = 60s;
        .probe = {
                .url = "/";
                .interval = 5s;
                .timeout = 2s;
                .window = 5;
                .threshold = 3;
        }
}

backend srv2{
        .host = "srv2";
        .port = "80";
        .first_byte_timeout = 300s;
        .connect_timeout = 5s;
        .between_bytes_timeout = 60s;
        .probe = {
                .url = "/";
                .interval = 5s;
                .timeout = 2s;
                .window = 5;
                .threshold = 3;
        }
}

backend srv3 {
        .host = "srv3";
        .port = "80";
        .first_byte_timeout = 300s;
        .connect_timeout = 5s;
        .between_bytes_timeout = 60s;
        .probe = {
                .url = "/";
                .interval = 5s;
                .timeout = 2s;
                .window = 5;
                .threshold = 3;
        }
}

Varnish says my backends are healthy at the 503 moment :

varnishadm debug.health
Backend srv1 is Healthy
Current states  good:  5 threshold:  3 window:  5
Average responsetime of good probes: 0.070728
Oldest                                                    Newest
================================================================
4444444444444444444444444444444444444444444444444444444444444444 Good IPv4
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX Good Xmit
RRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRR Good Recv
HHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHH Happy
Backend srv2 is Healthy
Current states  good:  5 threshold:  3 window:  5
Average responsetime of good probes: 0.089797
Oldest                                                    Newest
================================================================
4444444444444444444444444444444444444444444444444444444444444444 Good IPv4
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX Good Xmit
RRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRR Good Recv
HHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHH Happy
Backend srv3 is Healthy
Current states  good:  5 threshold:  3 window:  5
Average responsetime of good probes: 0.068935
Oldest                                                    Newest
================================================================
4444444444444444444444444444444444444444444444444444444444444444 Good IPv4
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX Good Xmit
RRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRR Good Recv
HHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHH Happy

I run multiple websites (around 200 domains) without other issues.

Varnishstat report some errors connecting the backends

Varnish #1

  13+23:09:28
    Hitrate ratio:        3        3        3
    Hitrate avg:     0.7669   0.7669   0.7669

[...]
               8         0.00         0.00 backend_fail - Backend conn. failures

Varnish #2

13+05:56:44
Hitrate ratio:        4        4        4
Hitrate avg:     0.8783   0.8783   0.8783

 [...]
          16         0.00         0.00 backend_fail - Backend conn. failures

Error can occure on a POST or a GET

POST with FetchError c backend write error: 0 (Success)

   23 SessionOpen  c xxx 40518 :80
   23 ReqStart     c xxx 40518 1750308108
   23 RxRequest    c POST
   23 RxURL        c /index.php?option=com_jce&task=plugin&plugin=imgmanager&file=imgmanager&method=form&cid=20&6bc427c8a7981f4fe1f5ac65c1246b5f=cf6dd3cf1923c950586d0dd595c8e20b
   23 RxProtocol   c HTTP/1.1
   23 RxHeader     c Reverse-Via: xxxx
   23 RxHeader     c Host: xxxxx
   23 RxHeader     c Content-Type: multipart/form-data; boundary=---------------------------41184676334
   23 RxHeader     c User-Agent: BOT/0.1 (BOT for JCE)
   23 RxHeader     c Connection: Keep-Alive
   23 RxHeader     c Content-Length: 5000
   23 VCL_call     c recv pass
   23 VCL_call     c hash
   23 Hash         c /index.php?option=com_jce&task=plugin&plugin=imgmanager&file=imgmanager&method=form&cid=20&6bc427c8a7981f4fe1f5ac65c1246b5f=cf6dd3cf1923c950586d0dd595c8e20b
   23 Hash         c xxxx
   23 VCL_return   c hash
   23 VCL_call     c pass pass
   23 Backend      c 46 cluster srv2
   23 FetchError   c backend write error: 0 (Success)
   23 VCL_call     c error deliver
   23 VCL_call     c deliver deliver
   23 TxProtocol   c HTTP/1.1
   23 TxStatus     c 503
   23 TxResponse   c Service Unavailable
   23 TxHeader     c Server: Varnish
   23 TxHeader     c Content-Type: text/html; charset=utf-8
   23 TxHeader     c Retry-After: 5
   23 TxHeader     c Content-Length: 419
   23 TxHeader     c Accept-Ranges: bytes
   23 TxHeader     c Date: Tue, 28 Jan 2014 22:18:53 GMT
   23 TxHeader     c X-Varnish: 1750308108
   23 TxHeader     c Age: 0
   23 TxHeader     c Via: 1.1 varnish
   23 TxHeader     c Connection: close
   23 TxHeader     c X-Cache: MISS from Varnish
   23 Length       c 419
   23 ReqEnd       c 1750308108 1390947533.416723251 1390947533.822463989 0.000115156 0.405680656 0.000060081

GET with FetchError c no backend connection

   52 ReqStart     c xxx 57491 1750328476
   52 RxRequest    c GET
   52 RxURL        c /filestore/retriever.flv
   52 RxProtocol   c HTTP/1.1
   52 RxHeader     c Reverse-Via: xxx
   52 RxHeader     c Host: xxxx
   52 RxHeader     c Cookie: ISAWPLB{2722D8D3-4E35-4741-92E0-22ADE0EA8C7F}={FD7F277E-829D-4B70-8BCA-9DCB3390060F}
   52 RxHeader     c Referer: xxxx
   52 RxHeader     c User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; Trident/7.0; MAARJS; rv:11.0) like Gecko
   52 RxHeader     c Accept: */*
   52 RxHeader     c Accept-Language: nb-NO
   52 RxHeader     c x-flash-version: 12,0,0,38
   52 RxHeader     c Cache-Control: no-cache
   52 RxHeader     c Connection: Keep-Alive
   52 VCL_call     c recv lookup
   52 VCL_call     c hash
   52 Hash         c /filestore/retriever.flv
   52 Hash         c xxx
   52 VCL_return   c hash
   52 VCL_call     c miss fetch
   52 FetchError   c no backend connection
   52 VCL_call     c error deliver
   52 VCL_call     c deliver deliver
   52 TxProtocol   c HTTP/1.1
   52 TxStatus     c 503
   52 TxResponse   c Service Unavailable
   52 TxHeader     c Server: Varnish
   52 TxHeader     c Content-Type: text/html; charset=utf-8
   52 TxHeader     c Retry-After: 5
   52 TxHeader     c Content-Length: 419
   52 TxHeader     c Accept-Ranges: bytes
   52 TxHeader     c Date: Tue, 28 Jan 2014 23:00:53 GMT
   52 TxHeader     c X-Varnish: 1750328476
   52 TxHeader     c Age: 0
   52 TxHeader     c Via: 1.1 varnish
   52 TxHeader     c Connection: close
   52 TxHeader     c X-Cache: MISS from Varnish
   52 Length       c 419
   52 ReqEnd       c 1750328476 1390950053.502151966 1390950053.502464533 1.025068998 0.000263214 0.000049353

I have more entries with

FetchError   c http first read error: -1 0 (Success)
FetchError   c Could not get storage
FetchError   c http first read error: -1 11 (Resource temporarily unavailable)

Apache timeout set to 300 seconds, keepalive connections is disabled.

How can Varnish determine a server error whereas the probe

I hope being as clear as possible. If you need more information let me know.

Thank you.

share|improve this question
    
Try adding this to the command-line startup of Varnish: -p http_max_hdr=256 –  Nathan C Jan 29 at 14:46

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Browse other questions tagged or ask your own question.