qdm12 / gluetun

VPN client in a thin Docker container for multiple VPN providers, written in Go, and using OpenVPN or Wireguard, DNS over TLS, with a few proxy servers built-in.
https://hub.docker.com/r/qmcgaw/gluetun
MIT License
8.14k stars 373 forks source link

Bug: Logs flooded with "Proxy-Authorization header not found" after setting HTTP User, Password #1398

Open Stylback opened 1 year ago

Stylback commented 1 year ago

Is this urgent?

No

Host OS

Ubuntu Server 22.04 LTS

CPU arch

x86_64

VPN service provider

Mullvad

What are you using to run the container

docker-compose

What is the version of Gluetun

Running version latest built on 2022-12-31T17:50:58.654Z (commit ea40b84)

What's the problem 🤔

Tl;DR: Other containers trying to use the Gluetun-container's HTTP proxy will produce a log entry for every request with INFO [http proxy] Proxy-Authorization header not found from [docker-ip]:[port].

Hi! I've been spending the last few evenings testing out Gluetun. I have a media stack (qbittorrent, *arr, jellyfin) where each service have their own docker container. My goal have been to have a Gluetun container with Mullvad which I then could use as a proxy for other containers.

I noticed that if I have the HTTPPROXY_USER and HTTPPROXY_PASSWORD environment variables enabled, each service that connect to Gluetun's HTTP proxy with the given credentials will produce a log entry claiming the incoming request lacks a Proxy-Authorization header. The service will however still be able to complete its requests without issue.

This behaviour seems contradictory. I don't know if this is an inteded behaviour (did not see another issue on this) or if there is a missconfiguration on my end. Either way it is currently flooding my logs and I hope there is a way to resolve this without disabling proxy authentication.

Share your logs

2023-02-16T13:47:42+01:00 INFO [routing] default route found: interface eth0, gateway 172.31.0.1 and assigned IP 172.31.0.18
2023-02-16T13:47:42+01:00 INFO [routing] local ethernet link found: eth0
2023-02-16T13:47:42+01:00 INFO [routing] local ipnet found: 172.31.0.0/16
2023-02-16T13:47:42+01:00 INFO [firewall] enabling...
2023-02-16T13:47:42+01:00 INFO [firewall] enabled successfully
2023-02-16T13:47:42+01:00 INFO [storage] merging by most recent 13224 hardcoded servers and 13224 servers read from /gluetun/servers.json
2023-02-16T13:47:42+01:00 INFO Alpine version: 3.16.3
2023-02-16T13:47:42+01:00 INFO OpenVPN 2.4 version: 2.4.12
2023-02-16T13:47:42+01:00 INFO OpenVPN 2.5 version: 2.5.6
2023-02-16T13:47:42+01:00 INFO Unbound version: 1.15.0
2023-02-16T13:47:42+01:00 INFO IPtables version: v1.8.8
2023-02-16T13:47:42+01:00 INFO Settings summary:
├── VPN settings:
|   ├── VPN provider settings:
|   |   ├── Name: mullvad
|   |   └── Server selection settings:
|   |       ├── VPN type: openvpn
|   |       ├── Cities: stockholm
|   |       └── OpenVPN server selection settings:
|   |           └── Protocol: UDP
|   └── OpenVPN settings:
|       ├── OpenVPN version: 2.5
|       ├── User: [set]
|       ├── Password: [set]
|       ├── Network interface: tun0
|       ├── Run OpenVPN as: root
|       └── Verbosity level: 1
├── DNS settings:
|   ├── DNS server address to use: 127.0.0.1
|   ├── Keep existing nameserver(s): no
|   └── DNS over TLS settings:
|       └── Enabled: no
├── Firewall settings:
|   ├── Enabled: yes
|   └── Outbound subnets:
|       └── 192.168.1.0/24
├── Log settings:
|   └── Log level: INFO
├── Health settings:
|   ├── Server listening address: 127.0.0.1:9999
|   ├── Target address: cloudflare.com:443
|   ├── Read header timeout: 100ms
|   ├── Read timeout: 500ms
|   └── VPN wait durations:
|       ├── Initial duration: 6s
|       └── Additional duration: 5s
├── Shadowsocks server settings:
|   └── Enabled: no
├── HTTP proxy settings:
|   ├── Enabled: yes
|   ├── Listening address: :8888
|   ├── User: stylback
|   ├── Password: [set]
|   ├── Stealth mode: no
|   ├── Log: no
|   ├── Read header timeout: 1s
|   └── Read timeout: 3s
├── Control server settings:
|   ├── Listening address: :8000
|   └── Logging: yes
├── OS Alpine settings:
|   ├── Process UID: 1000
|   ├── Process GID: 1000
|   └── Timezone: Europe/Stockholm
├── Public IP settings:
|   ├── Fetching: every 12h0m0s
|   └── IP file path: /tmp/gluetun/ip
└── Version settings:
    └── Enabled: yes
2023-02-16T13:47:42+01:00 INFO [routing] default route found: interface eth0, gateway 172.31.0.1 and assigned IP 172.31.0.18
2023-02-16T13:47:42+01:00 INFO [routing] adding route for 0.0.0.0/0
2023-02-16T13:47:42+01:00 INFO [firewall] setting allowed subnets...
2023-02-16T13:47:42+01:00 INFO [routing] default route found: interface eth0, gateway 172.31.0.1 and assigned IP 172.31.0.18
2023-02-16T13:47:42+01:00 INFO [routing] adding route for 192.168.1.0/24
2023-02-16T13:47:42+01:00 INFO [dns over tls] using plaintext DNS at address 1.1.1.1
2023-02-16T13:47:42+01:00 INFO [http proxy] listening on :8888
2023-02-16T13:47:42+01:00 INFO [http server] http server listening on [::]:8000
2023-02-16T13:47:42+01:00 INFO [healthcheck] listening on 127.0.0.1:9999
2023-02-16T13:47:42+01:00 INFO [firewall] allowing VPN connection...
2023-02-16T13:47:42+01:00 INFO [openvpn] OpenVPN 2.5.6 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 17 2022
2023-02-16T13:47:42+01:00 INFO [openvpn] library versions: OpenSSL 1.1.1s  1 Nov 2022, LZO 2.10
2023-02-16T13:47:42+01:00 INFO [openvpn] TCP/UDP: Preserving recently used remote address: [AF_INET][redacted]:1194
2023-02-16T13:47:42+01:00 INFO [openvpn] UDP link local: (not bound)
2023-02-16T13:47:42+01:00 INFO [openvpn] UDP link remote: [AF_INET][redacted]:1194
2023-02-16T13:47:42+01:00 WARN [openvpn] 'link-mtu' is used inconsistently, local='link-mtu 1557', remote='link-mtu 1558'
2023-02-16T13:47:42+01:00 WARN [openvpn] 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo'
2023-02-16T13:47:42+01:00 INFO [openvpn] [redacted] Peer Connection Initiated with [AF_INET][redacted]:1194
2023-02-16T13:47:48+01:00 INFO [healthcheck] program has been unhealthy for 6s: restarting VPN
2023-02-16T13:47:48+01:00 INFO [vpn] stopping
2023-02-16T13:47:48+01:00 INFO [vpn] starting
2023-02-16T13:47:48+01:00 INFO [firewall] allowing VPN connection...
2023-02-16T13:47:48+01:00 INFO [openvpn] OpenVPN 2.5.6 x86_64-alpine-linux-musl [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Apr 17 2022
2023-02-16T13:47:48+01:00 INFO [openvpn] library versions: OpenSSL 1.1.1s  1 Nov 2022, LZO 2.10
2023-02-16T13:47:48+01:00 INFO [openvpn] TCP/UDP: Preserving recently used remote address: [AF_INET]185.65.135.83:1194
2023-02-16T13:47:48+01:00 INFO [openvpn] UDP link local: (not bound)
2023-02-16T13:47:48+01:00 INFO [openvpn] UDP link remote: [AF_INET][redacted]:1194
2023-02-16T13:47:48+01:00 WARN [openvpn] 'link-mtu' is used inconsistently, local='link-mtu 1557', remote='link-mtu 1558'
2023-02-16T13:47:48+01:00 WARN [openvpn] 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo'
2023-02-16T13:47:48+01:00 INFO [openvpn] [redacted] Peer Connection Initiated with [AF_INET][redacted]:1194
2023-02-16T13:47:55+01:00 INFO [openvpn] setsockopt TCP_NODELAY=1 failed
2023-02-16T13:47:55+01:00 INFO [openvpn] TUN/TAP device tun0 opened
2023-02-16T13:47:55+01:00 INFO [openvpn] /sbin/ip link set dev tun0 up mtu 1500
2023-02-16T13:47:55+01:00 INFO [openvpn] /sbin/ip link set dev tun0 up
2023-02-16T13:47:55+01:00 INFO [openvpn] /sbin/ip addr add dev tun0 10.8.0.84/16
2023-02-16T13:47:55+01:00 INFO [openvpn] UID set to nonrootuser
2023-02-16T13:47:55+01:00 INFO [openvpn] Initialization Sequence Completed
2023-02-16T13:47:55+01:00 INFO [ip getter] Public IP address is [redacted] (Sweden, Stockholm, Stockholm)
2023-02-16T13:47:55+01:00 INFO [vpn] You are running on the bleeding edge of latest!
2023-02-16T13:47:56+01:00 INFO [healthcheck] healthy!
2023-02-16T13:48:07+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52112
2023-02-16T13:48:07+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52112
2023-02-16T13:48:07+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52122
2023-02-16T13:48:07+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52142
2023-02-16T13:48:11+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52146
2023-02-16T13:48:11+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52170
2023-02-16T13:48:11+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52186
2023-02-16T13:48:11+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52206
2023-02-16T13:48:11+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52222
2023-02-16T13:48:11+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52244
2023-02-16T13:48:11+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52262
2023-02-16T13:48:11+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52282
2023-02-16T13:48:11+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:52298
2023-02-16T13:48:13+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59274
2023-02-16T13:48:13+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59290
2023-02-16T13:48:13+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59306
2023-02-16T13:48:13+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59318
2023-02-16T13:48:13+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59326
2023-02-16T13:48:14+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59354
2023-02-16T13:48:14+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59372
2023-02-16T13:48:14+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59384
2023-02-16T13:48:14+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59404
2023-02-16T13:48:14+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59410
2023-02-16T13:48:14+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59426
2023-02-16T13:48:14+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59442
2023-02-16T13:48:14+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59462
2023-02-16T13:48:14+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:59478
2023-02-16T13:48:42+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:54578
2023-02-16T13:48:42+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:54580
2023-02-16T13:48:59+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:46546
2023-02-16T13:48:59+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:46554
2023-02-16T13:48:59+01:00 INFO [http proxy] Proxy-Authorization header not found from 172.31.0.1:46582

Share your configuration

version: "3"
services:
  gluetun:
    container_name: gluetun
    image: qmcgaw/gluetun
    cap_add:
      - NET_ADMIN
    devices:
      - /dev/net/tun:/dev/net/tun
    ports:
      - 8888:8888/tcp # HTTP proxy
      - 8388:8388/tcp # Shadowsocks
      - 8388:8388/udp # Shadowsocks
    volumes:
      - ./data:/gluetun
    environment:
      - VPN_SERVICE_PROVIDER=mullvad
      - VPN_TYPE=openvpn
      - OPENVPN_USER=[redacted]
      - SERVER_CITIES=Stockholm
      - TZ=Europe/Stockholm
      - HTTPPROXY=on
      - FIREWALL_OUTBOUND_SUBNETS=192.168.1.0/24
      - DOT=off
      - HTTPPROXY_USER=stylback
      - HTTPPROXY_PASSWORD=[redacted]
    restart: always

networks:
  default:
    name: boulder
damajor commented 1 year ago

Same issue there.

huylenguyen commented 1 year ago

I'm also observing this issue.

Daviid-P commented 1 year ago

Same here

version: "3"
services:
  gluetun:
    image: qmcgaw/gluetun:latest
    container_name: gluetun_usa
    cap_add:
      - NET_ADMIN
    network_mode: bridge
    ports:
      - 30000:8888/tcp # HTTP proxy
      - 30001:8388/tcp # Shadowsocks
      - 30001:8388/udp # Shadowsocks
    volumes:
      - /home/david/gluetun/usa/data:/gluetun
    environment:
      - OPENVPN_USER=redacted
      - OPENVPN_PASSWORD=redacted
      - VPNSP=private internet access
      - REGION=usa
      - TZ=Europe/Madrid
      - HTTPPROXY=on
      - HTTPPROXY_LOG=off
      - HTTPPROXY_PORT=8888
      - HTTPPROXY_USER=daviid
      - HTTPPROXY_PASSWORD=redacted
      - HTTPPROXY_STEALTH=on
      - SHADOWSOCKS=on
    restart: always
rubeo-O commented 3 weeks ago

I am seeing the same thing on my end. Services can connect to the proxy just fine but my logs are littered with these messages. Is this a configuration error on my part?