How to debug varnish - Error (null) Backend fetch failed

[thomasmoreaumaster]

API Platform version(s) affected: 2.5.1

Description
Got a varnish error on a specific request in production but not in preproduction.

Error (null) Backend fetch failed
Backend fetch failed

Guru Meditation:
XID: (null)

Additional Context
We have the same environment and cluster configuration in pre-production & production, but in production this specific request returns this error.

We have also tried to put the same database just to try to debug and got the same results.

We have tried as well to increase the configuration as following :

CMD ["varnishd", "-F", "-f", "/etc/varnish/default.vcl", "-p", "http_resp_hdr_len=128k", "-p", "http_resp_size=128k", "-p", "http_req_hdr_len=64k", "-p", "workspace_backend=256k", "-p", "workspace_client=256k", "-p", "http_max_hdr=256"]

So we were wondering how to debug varnish ?

Thanks a lot for your time :)
Thomas.

[teohhanhui]

Varnish sends a X-Varnish response header. You can use it to match the log entries from varnishlog.

[thomasmoreaumaster]

thanks @teohhanhui,

This is what i can find in the log in my varnish pod.

*   << Request  >> 163848    
-   Begin          req 163847 rxreq
-   Timestamp      Start: 1576598269.813483 0.000000 0.000000
-   Timestamp      Req: 1576598269.813483 0.000000 0.000000
-   VCL_use        boot
-   ReqStart       10.132.0.3 57032 a0
-   ReqMethod      GET
-   ReqURL         /api/v1/partners/29/products
-   ReqProtocol    HTTP/1.1
-   ReqHeader      Host: www.monsite.org
-   ReqHeader      accept: application/json, text/plain, */*
-   ReqHeader      authorization: Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiJ9.eyJpYXQiOjE1NzY1OTQ4NDgsImV4cCI6MTU3NjYwMjA0OCwicm9sZXMiOlsiUk9MRV9VU0VSIl0sInVzZXJuYW1lIjoiVGVhbSBEb25zIn0.pH6MkaN_cNuRPAD9Sd9VQ6zxrVS93KrhMTbgWcSOdefYI3MsJDiFRWQkycz0GxFmjNu_7IcWhF50SXRP2VTtBXJ
-   ReqHeader      user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/74.0.3729.131 Safari/537.36
-   ReqHeader      referer: https://www.monsite.org/accueil
-   ReqHeader      accept-encoding: gzip, deflate, br
-   ReqHeader      accept-language: en-US,en;q=0.9,fr;q=0.8
-   ReqHeader      Cookie: _ga=GA1.2.323822874.1576587294; _gid=GA1.2.267626463.1576587294; G_ENABLED_IDPS=google; fbm_787293838383147=base_domain=.www.monsite.org; fbsr_787293838383147=BWP66qpetZfq5UZjH29b-OTIfgunwxCpVekffQwyK94.eyJ1c2VyX2lkIjoiMTAxNjI2ODU4ODQzMDA1MzMiLCJj
-   ReqHeader      X-Cloud-Trace-Context: 20bb825fe65d7417b29e2c4ee7a0183e/5499294814462808795
-   ReqHeader      Via: 1.1 google
-   ReqHeader      X-Forwarded-Proto: https
-   ReqHeader      Connection: Keep-Alive
-   VCL_call       RECV
-   ReqUnset       Host: www.monsite.org
-   ReqHeader      host: www.monsite.org
-   VCL_return     pass
-   VCL_call       HASH
-   VCL_return     lookup
-   VCL_call       PASS
-   VCL_return     fetch
-   Link           bereq 163849 pass
-   Timestamp      Fetch: 1576598270.969696 1.156213 1.156213
-   RespProtocol   HTTP/1.1
-   RespStatus     503
-   RespReason     Backend fetch failed
-   RespHeader     Server: Varnish
-   RespHeader     X-Varnish: 163848
-   RespHeader     Age: 0
-   RespHeader     Via: 1.1 varnish (Varnish/6.3)
-   VCL_call       DELIVER
-   VCL_return     deliver
-   Timestamp      Process: 1576598270.969707 1.156224 0.000010
-   Filters        
-   RespHeader     Content-Length: 289
-   RespHeader     Connection: keep-alive
-   Timestamp      Resp: 1576598270.969731 1.156248 0.000024
-   ReqAcct        2571 0 2571 158 289 447
-   End 

The thing is i don't know what to think about it ?

Can you help please ?
thanks
Thomas.

[teohhanhui]

I don't know. The log you have here doesn't show anything.

[thomasmoreaumaster]

It came from the size of the response, i did not paginate the results of the request and Varnish doesn't like big result.

So i implemented pagination in my API and everything works fine :)

Thanks a lot for your time,
Thomas.