Php+Nginx+Varnish on docker-compose, ubuntu18

Question

!Important. SOLUTION FOUND. Everything below is working fine for me. And this is almost the only case when you may copy solution from the question. For it read "My Configuration" section

Main Question

On an attempt to open the homepage (through https 443 or http 80 does not matter) I see 503 Varnish error. It looks like Varnish cannot access Nginx back.

Varnish Request Log

*   << Request  >> 20        
-   Begin          req 19 rxreq
-   Timestamp      Start: 1587133057.263443 0.000000 0.000000
-   Timestamp      Req: 1587133057.263443 0.000000 0.000000
-   VCL_use        boot
-   ReqStart       192.168.112.7 46616 a0
-   ReqMethod      GET
-   ReqURL         /
-   ReqProtocol    HTTP/1.0
-   ReqHeader      X-Real-IP: 192.168.112.1
-   ReqHeader      X-Forwarded-For: 192.168.112.1
-   ReqHeader      X-Forwarded-Proto: https
-   ReqHeader      X-Forwarded-Port: 443
-   ReqHeader      Host: magento2.docker
-   ReqHeader      Connection: close
-   ReqHeader      Cache-Control: max-age=0
-   ReqHeader      Upgrade-Insecure-Requests: 1
-   ReqHeader      User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/81.0.4044.92 Safari/537.36
-   ReqHeader      Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9
-   ReqHeader      Sec-Fetch-Site: none
-   ReqHeader      Sec-Fetch-Mode: navigate
-   ReqHeader      Sec-Fetch-User: ?1
-   ReqHeader      Sec-Fetch-Dest: document
-   ReqHeader      Accept-Encoding: gzip, deflate, br
-   ReqHeader      Accept-Language: ru-RU,ru;q=0.9,en-US;q=0.8,en;q=0.7,be;q=0.6
-   ReqHeader      Cookie: mage-banners-cache-storage=%7B%7D; _ga=GA1.2.164324136.1586263205; private_content_version=b9dd22e11f7865017754892a623f70f0; mage-cache-storage=%7B%7D; mage-cache-storage-section-invalidation=%7B%7D; mage-messages=; recently_viewed_product=%7B%7D
-   ReqUnset       X-Forwarded-For: 192.168.112.1
-   ReqHeader      X-Forwarded-For: 192.168.112.1, 192.168.112.7
-   VCL_call       RECV
-   VCL_return     pass
-   VCL_call       HASH
-   VCL_return     lookup
-   VCL_call       PASS
-   VCL_return     fetch
-   Link           bereq 21 pass
-   Timestamp      Fetch: 1587133057.263600 0.000157 0.000157
-   RespProtocol   HTTP/1.1
-   RespStatus     503
-   RespReason     Backend fetch failed
-   RespHeader     Date: Fri, 17 Apr 2020 14:17:37 GMT
-   RespHeader     Server: Varnish
-   RespHeader     Content-Type: text/html; charset=utf-8
-   RespHeader     Retry-After: 5
-   RespHeader     X-Varnish: 20
-   RespHeader     Age: 0
-   RespHeader     Via: 1.1 varnish (Varnish/6.2)
-   VCL_call       DELIVER
-   VCL_return     deliver
-   Timestamp      Process: 1587133057.263609 0.000166 0.000009
-   Filters        
-   RespHeader     Content-Length: 279
-   RespHeader     Connection: close
-   Timestamp      Resp: 1587133057.263640 0.000197 0.000031
-   ReqAcct        1164 0 1164 242 279 521
-   End  

*   << BeReq    >> 21        
-   Begin          bereq 20 pass
-   VCL_use        boot
-   Timestamp      Start: 1587133057.263477 0.000000 0.000000
-   BereqMethod    GET
-   BereqURL       /
-   BereqProtocol  HTTP/1.0
-   BereqHeader    X-Real-IP: 192.168.112.1
-   BereqHeader    X-Forwarded-Proto: https
-   BereqHeader    X-Forwarded-Port: 443
-   BereqHeader    Host: magento2.docker
-   BereqHeader    Cache-Control: max-age=0
-   BereqHeader    Upgrade-Insecure-Requests: 1
-   BereqHeader    User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/81.0.4044.92 Safari/537.36
-   BereqHeader    Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9
-   BereqHeader    Sec-Fetch-Site: none
-   BereqHeader    Sec-Fetch-Mode: navigate
-   BereqHeader    Sec-Fetch-User: ?1
-   BereqHeader    Sec-Fetch-Dest: document
-   BereqHeader    Accept-Encoding: gzip, deflate, br
-   BereqHeader    Accept-Language: ru-RU,ru;q=0.9,en-US;q=0.8,en;q=0.7,be;q=0.6
-   BereqHeader    Cookie: mage-banners-cache-storage=%7B%7D; _ga=GA1.2.164324136.1586263205; private_content_version=b9dd22e11f7865017754892a623f70f0; mage-cache-storage=%7B%7D; mage-cache-storage-section-invalidation=%7B%7D; mage-messages=; recently_viewed_product=%7B%7D
-   BereqHeader    X-Forwarded-For: 192.168.112.1, 192.168.112.7
-   BereqProtocol  HTTP/1.1
-   BereqHeader    X-Varnish: 21
-   VCL_call       BACKEND_FETCH
-   VCL_return     fetch
-   FetchError     backend default: fail errno 111 (Connection refused)
-   Timestamp      Beresp: 1587133057.263561 0.000084 0.000084
-   Timestamp      Error: 1587133057.263564 0.000087 0.000002
-   BerespProtocol HTTP/1.1
-   BerespStatus   503
-   BerespReason   Service Unavailable
-   BerespReason   Backend fetch failed
-   BerespHeader   Date: Fri, 17 Apr 2020 14:17:37 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
-   Length         279
-   BereqAcct      0 0 0 0 0 0
-   End    

My Configuration

Source code can be found here: https://github.com/zhartaunik/magento2-docker

Here are some necessary moments for history:

docker-compose.yml

version: "3"
services:
  varnish:
    container_name: varnish
    build:
      context: varnish/
    ports:
      - 6081:6081

  nginx:
    container_name: nginx
    build:
      context: nginx/
    working_dir: /etc/nginx
    ports:
      # {internal_in_docker}:{external_from_browser}
      - 80:80
      - 443:443
      - 8001:8001
    volumes:
      - ./magento:/var/www/magento
    env_file:
      - ./.env
...

nginx/etc/vhost.conf

upstream fastcgi_backend {
  server magento:9000;
}

server {
    listen 80;
    listen 443 ssl;

    server_name _;
    ssl on;
    ssl_certificate /etc/nginx/ssl/magento.crt;
    ssl_certificate_key /etc/nginx/ssl/magento.key;
    keepalive_timeout 300s;

    location / {
        proxy_pass http://varnish:6081;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Forwarded-Proto https;
        proxy_set_header X-Forwarded-Port 443;
        proxy_set_header Host $host;
        proxy_read_timeout 600s;
    }
}

server {
    listen 8001;

    server_name localhost;

    set $MAGE_ROOT /var/www/magento;
    set $MAGE_MODE developer;

I faced the issue because I didn't use the desired varnish.vcl. If you use this one, everything should work fine for you

varnish/etc/varnish.vcl

vcl 4.0;

import std;
# The minimal Varnish version is 4.0
# For SSL offloading, pass the following header in your proxy server or load balancer: 'SSL-OFFLOADED: https'

backend default {
    .host = "nginx";
    .port = "8001";
}
...

How in my understanding it should work

• We open through browser homepage: https://magento2.docker/
• As inside docker-compose.yml configured that Nginx is listening to 443 port we go to it's vhost.conf section (1st part)
• Because of the row proxy_pass http://varnish:6081; we are directing to varnish container through 6081 port.
• nginx_container> telnet varnish 6081 returns SUCCESS
• According to docker-compose.yml varnish configured to listen 6081 (Is it really required to add this port to yml?) we walk to varnish/etc/varnish.vcl (Could this file contain only backend default section for debug purpose only?)
• Inside backend default we see host=nginx, port=8001. This should direct us to Nginx. varnish_container> telnet Nginx 8001 returns SUCCESS. However looks like directly here WE ARE NOT GOING to Nginx
• The 2nd part of vhost.conf doesn't start to work. If we try to open http://magento2.docker:8001/ Nginx resolves this host and application start working.

What I'm looking for here

• The solution to a problem
• Two bolded questions above
• Any suggestions how to debug? How to check from varnish container what does respond Nginx?

Update #1 (Solution was found)

I've tested your Docker setup and the main thing I notice is that the backend definition of /etc/varnish/default.vcl in your varnish container is the following: backend default { .host = "127.0.0.1"; .port = "8080"; }

I found a mistake in DockerFile. I used the default config with wrong host/port settings. I changed this value and everything started working fine.

Here are the sources (all of them you may find at https://github.com/zhartaunik/magento2-docker):

varnish/Dockerfile

FROM varnish:6.2

COPY etc/varnish.vcl /etc/varnish/
COPY bin/docker-entrypoint.sh /docker-entrypoint.sh

RUN chmod +x /docker-entrypoint.sh

ENV VARNISH_CONFIG  /etc/varnish/varnish.vcl
ENV VARNISH_STORAGE malloc,2048m
ENV VARNISH_LISTEN  :6081
ENV VARNISH_MANAGEMENT_LISTEN 127.0.0.1:6082
EXPOSE 6081
EXPOSE 6082

ENTRYPOINT ["/bin/bash", "/docker-entrypoint.sh"]

varnish/bin/docker-entrypoint.sh

#!/bin/bash

set -e

exec varnishd \
    -j unix,user=vcache \
    -F \
    -f ${VARNISH_CONFIG} \
    -s ${VARNISH_STORAGE} \
    -a ${VARNISH_LISTEN} \
    -T ${VARNISH_MANAGEMENT_LISTEN} \
    -p feature=+esi_ignore_https \
    ${VARNISH_DAEMON_OPTS}

I also removed depends_on section.

Answer 1

I've tested your Docker setup and the main thing I notice is that the backend definition of /etc/varnish/default.vcl in your varnish container is the following:

backend default {
    .host = "127.0.0.1";
    .port = "8080";
}

This of course results in a Connection refused error.

When I change it to the following, it does work

backend default {
    .host = "nginx";
    .port = "8001";
}

Just before sending the 1st request to Varnish, I ran the following command to check which backend will be used:

Debugging

root@a5ddd5873f9a:/etc/varnish# varnishlog -i backendopen
*   << BeReq    >> 17
-   BackendOpen    25 default 172.31.0.9 8001 172.31.0.2 58070

*   << Request  >> 16

*   << Session  >> 15

Once the connection is open, the BackendOpen tag won't appear in your varnishlog output.

In your case BackendOpen never appeared in the logs, because you never successfully opened up a backend connection.

An easy way to continuously monitor the health of your backend servers in Varnish, is by associating probes as illustrated below:

backend default {
    .host = "nginx";
    .port = "8001";
    .probe = {
        .url = "/";
        .timeout = 1s;
        .interval = 5s;
        .window = 5;
        .threshold = 3;
    }
}

You can monitor the health by running varnishlog -g raw as illustrated below:

root@a5ddd5873f9a:/etc/varnish# varnishlog -g raw
  0 Backend_health - default Still sick 4---X-R- 0 3 5 0.001804 0.000000 HTTP/1.1 404 Not Found

In this case the backend is sick because the / URL returns a HTTP/1.1 404 Not Found. If you make sure this is a HTTP/1.1 200 OK, the health check will pass, and you will not what backend Varnish trying to connect to.

Potential dependency issues

However, there might also be some depends_on issues in your docker-compose.yml file:

• Varnish depends on Nginx. If Nginx isn't started on time, Varnish cannot resolve the nginx hostname, which it uses as its backend.
• Nginx depends on Varnish. If Varnish isn't started on time, Nginx cannot resolve the varnish hostname it needs to proxy its traffic through.

It's a bit of a circular dependency thing. Please check ahead of time, to ensure you're not experiencing these issues.

To make your setup work, I had to make sure Nginx depended on Varnish, otherwise the Nginx container wouldn't start. But I had to remove the Nginx dependency from Varnis, otherwise I was stuck in a circular dependency loop.

Conclusion

In your docker-compose setup, your VCL file doesn't point to the right Nginx backend.

A less likely issue is misconfigured dependencies: if the containers aren't started in the right order, hostnames will be not be accessible at the time the container needs them for proxying reasons. Again: not that likely.