Hulp nodig bij debuggen Ubuntu 22.04 issue

[smeerbartje]

Ik heb een VPS bij Strato, vrij simpel ding:

• 2 CPU vCores
• 4 GB RAM gegarandeerd
• 100 GB NVMe SSD

Ik gebruik hem om een hobby-project op te draaien. Dit lukt wel, alleen zo'n twee keer per week heb ik een probleem met dat bakkie. Allereerst even iets over de staat van de VPS:

• Provisionning met ansible
• Er staat niet veel op, beetje dotfiles config, docker installatie, etc.
• Tailscale om het bakkie te benaderen via SSH
• Er draaien een aantal services via een grote docker-compose file.
• Poortje 80+443 staan open en worden geserveerd door Caddy (reverse proxy, draait ook in container)
• Deze reverse proxy zorgt ervoor dat het spul in de containers wordt ge-exposed naar de buitenwereld

Nu het probleem: ik kan dit het beste uitleggen als volgt:

• Op moment één werkt alles goed
• Dan opeens is het ding op geen enkele manier meer te bereiken. Via poort 80 niet, 443 niet en ook via ssh niet.
• Het enige dat ik dan nog kan doen is via de Strato admin console een "VNC sessie" opzetten en op die manier dus de controle overnemen. Ik kan dan prima inloggen op de machine.
• Ik kan dan dus ook de staat van de VM bekijken, logfiles inzien, etc.

Alleen nu mijn probleem: ik weet dus niet hoe ik zoiets moet debuggen . Mijn kennis ontbreekt hier. Ik heb al eens gekeken naar de output van systemctl status systemd-networkd, en daar zie ik dan wel wat rare foutmeldingen. Echter wat nu precies de oorzaak is: geen idee. Zie ook bijgevoegde screenshots. Het lijkt iets met de network stack te zijn. Een simpele reboot lost alles op.

Mijn vraag aan jullie

Hoe kan ik zoiets nu debuggen? Stel de VM is weer in deze broken state, welke commando's kan ik dan uitvoeren om een beter beeld te krijgen bij de oorzaak van dit?

Screenshots van de "broken state"

[Hero of Time]

Wat is je netwerk configuratie van de VPS? Gebruik je een bridge voor de containers? Er is iig iets gaande waardoor je NIC, ens6, geen IP kan vernieuwen, zoals in je log duidelijk staat aangegeven met gele tekst.

Kijk naast systemd-networkd ook naar je volledige journalctl uitvoer. Daar zou je wat meer hints moeten vinden over wat er gaande is.

[smeerbartje]

Hero of Time schreef op maandag 26 juni 2023 @ 18:33:
Wat is je netwerk configuratie van de VPS? Gebruik je een bridge voor de containers? Er is iig iets gaande waardoor je NIC, ens6, geen IP kan vernieuwen, zoals in je log duidelijk staat aangegeven met gele tekst.

Kijk naast systemd-networkd ook naar je volledige journalctl uitvoer. Daar zou je wat meer hints moeten vinden over wat er gaande is.

Hey! Dank voor je reactie. De VPS is vrij standaard Ubuntu 22.04 LTS.
De "/etc/netplan" directory bevat één file: 50-cloud-init.yaml. Inhoud is als volgt:

code:

# This file is generated from information provided by the datasource.  Changes
# to it will not persist across an instance reboot.  To disable cloud-init's
# network configuration capabilities, write a file
# /etc/cloud/cloud.cfg.d/99-disable-network-config.cfg with the following:
# network: {config: disabled}
network:
    ethernets:
        all:
            dhcp4: true
            dhcp6: true
            match:
                name: en*
    renderer: networkd
    version: 2

En als het probleem zich dus voordoet, dan die ik het volgende in de logs:

code:

Jun 23 17:11:12 playlist-exchange systemd-networkd[576]: veth358b593: Gained IPv6LL
Jun 25 11:34:09 playlist-exchange systemd-networkd[576]: ens6: Could not set DHCPv4 address: Connection timed out
Jun 25 11:34:09 playlist-exchange systemd-networkd[576]: ens6: Failed
Jun 25 11:44:36 playlist-exchange systemd-networkd[576]: veth53e5fc0: Lost carrier

Op dat moment is er dus helemaal geen interactie/communicatie meer mogelijk via het netwerk. De vraag is dus een beetje hoe het systeem in deze staat terecht komt.

[Hero of Time]

Je hebt 'veth' interfaces, virtuele ethernet adapters. Die moeten van Docker komen, dus wat heb je in je dockerfiles staan en hoe heb je Docker verder geconfigureerd voor je netwerk? Want die kan zich ook gaan bemoeien met zaken en daardoor de boel slopen. Dat merk je niet direct, maar pas als er iets als dhcp vernieuwd moet worden, zoals nu dus.

[smeerbartje]

Hero of Time schreef op dinsdag 27 juni 2023 @ 19:54:
Je hebt 'veth' interfaces, virtuele ethernet adapters. Die moeten van Docker komen, dus wat heb je in je dockerfiles staan en hoe heb je Docker verder geconfigureerd voor je netwerk? Want die kan zich ook gaan bemoeien met zaken en daardoor de boel slopen. Dat merk je niet direct, maar pas als er iets als dhcp vernieuwd moet worden, zoals nu dus.

Nogmaasls bedankt voor je tijd, @Hero of Time . Dit is allemaal nieuw voor mij en ontzettend leerzaam. Ik probeer zoveel mogelijk logs te verzamelen. Hopelijk vinden we de rootcause .

Hieronder drie stukjes info:

1. De output van networkctl op het moment dat het mis is
2. De output van fconfig op het moment dat het mis is
3. Mijn docker-compose file van alle containers die draaien op de bak

Zoals je ziet is het allemaal vrij recht-toe-recht aan. Een reverse proxy, een tweetal postgres instanties, wat apps en rabbitmq. Wat bedoel je precies met virtual interfaces? Dat zijn puur de docker images toch? Deze gaan op state "degraded" ten gevolge van het feit dat ens6 geen ip kan krijgen denk ik. Maar waarom kan ens6 geen ip krijgen? Kan ik dat proces -dus het verkrijgen van een ip- op de één of andere manier forceren op het moment dat het weer mis is?

Output van networkctl


Output ifconfig

code:

br-918ef6719d1a: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 172.18.0.1  netmask 255.255.0.0  broadcast 172.18.255.255
        inet6 fe80::42:c4ff:fe36:f6de  prefixlen 64  scopeid 0x20<link>
        ether 02:42:c4:36:f6:de  txqueuelen 0  (Ethernet)
        RX packets 17430949  bytes 4881800644 (4.8 GB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 17651544  bytes 3755558001 (3.7 GB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

docker0: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
        inet 172.17.0.1  netmask 255.255.0.0  broadcast 172.17.255.255
        ether 02:42:85:2b:d6:51  txqueuelen 0  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

ens6: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::1:e7ff:feb5:bb1  prefixlen 64  scopeid 0x20<link>
        ether 02:01:e7:b5:0b:b1  txqueuelen 1000  (Ethernet)
        RX packets 1582287  bytes 1528467292 (1.5 GB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 1680101  bytes 2690722331 (2.6 GB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet 127.0.0.1  netmask 255.0.0.0
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 1000  (Local Loopback)
        RX packets 45707  bytes 4301283 (4.3 MB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 45707  bytes 4301283 (4.3 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

tailscale0: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1280
        inet x.y.z.a  netmask 255.255.255.255  destination x.y.z.b
        inet6 fe80::9e22:1:e9c5:fc31  prefixlen 64  scopeid 0x20<link>
        inet6 <public dinges gedoe>
        unspec 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00  txqueuelen 500  (UNSPEC)
        RX packets 525886  bytes 28437584 (28.4 MB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 111929  bytes 1089210320 (1.0 GB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth3137250: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::d081:7ff:fe6e:66c5  prefixlen 64  scopeid 0x20<link>
        ether ee:48:46:c3:b9:31  txqueuelen 0  (Ethernet)
        RX packets 305235  bytes 83536559 (83.5 MB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 296426  bytes 97993259 (97.9 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth0b6353e: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::7c7e:2eff:fe6f:44aa  prefixlen 64  scopeid 0x20<link>
        ether 82:65:79:af:eb:f2  txqueuelen 0  (Ethernet)
        RX packets 1331641  bytes 103410205 (103.4 MB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 2460158  bytes 185230470 (185.2 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth46f99f6: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::98d9:7cff:fe93:1726  prefixlen 64  scopeid 0x20<link>
        ether c6:1e:92:93:8f:3e  txqueuelen 0  (Ethernet)
        RX packets 175167  bytes 1386160639 (1.3 GB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 172942  bytes 274217901 (274.2 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth737d2fc: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::3404:55ff:fec8:3571  prefixlen 64  scopeid 0x20<link>
        ether ba:ed:f9:7c:24:4a  txqueuelen 0  (Ethernet)
        RX packets 155246  bytes 268663457 (268.6 MB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 172634  bytes 26518443 (26.5 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth7bb98d9: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::f440:deff:fee4:b2ba  prefixlen 64  scopeid 0x20<link>
        ether ca:59:8a:de:16:b6  txqueuelen 0  (Ethernet)
        RX packets 6866695  bytes 1133522830 (1.1 GB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 7841843  bytes 698920916 (698.9 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth829bfb3: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::9415:f0ff:fe29:b095  prefixlen 64  scopeid 0x20<link>
        ether 82:c0:44:94:94:65  txqueuelen 0  (Ethernet)
        RX packets 172280  bytes 259079059 (259.0 MB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 174792  bytes 257164992 (257.1 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth98e10a4: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::9062:62ff:fe9c:96ac  prefixlen 64  scopeid 0x20<link>
        ether f6:18:dd:49:fd:24  txqueuelen 0  (Ethernet)
        RX packets 667204  bytes 1465717454 (1.4 GB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 873053  bytes 1439887699 (1.4 GB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

vetha664374: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet6 fe80::18b9:c6ff:fede:2baa  prefixlen 64  scopeid 0x20<link>
        ether 1a:b9:c6:de:2b:aa  txqueuelen 0  (Ethernet)
        RX packets 243941  bytes 65052388 (65.0 MB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 246818  bytes 63901809 (63.9 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

De docker-compose file

code:

services:

  caddy:
    image: 'caddy:latest'
    user: 1000:1000
    container_name: caddy
    restart: no
    ports:
      - "80:80"
      - "443:443"
      - "443:443/udp"
    volumes:
      - /srv/local/services/caddy/config:/etc/caddy
      - /srv/local/services/caddy/data:/data

  playlist-exchange-db:
    container_name: playlist-exchange-db
    image: postgres:latest
    restart: no
    user: 1000:1000
    volumes:
      - /srv/local/databases/playlist-exchange:/var/lib/postgresql/data
      - /tmp/dbs:/tmp/dbs
    ports:
      - 7001:5432
    environment:
      - TZ=Europe/Amsterdam
      - PG_TZ=Europe/Amsterdam
      - POSTGRES_USER=xxx
      - POSTGRES_PASSWORD=xxx

  plausible-db:
    container_name: plausible-db
    image: postgres:latest
    restart: no
    user: 1000:1000
    volumes:
      - /srv/local/databases/plausible:/var/lib/postgresql/data
      - /tmp/dbs:/tmp/dbs
    ports:
      - 7002:5432
    environment:
      - TZ=Europe/Amsterdam
      - PG_TZ=Europe/Amsterdam
      - POSTGRES_USER=xxx
      - POSTGRES_PASSWORD=xxx

  plausible-events-db:
    container_name: plausible-events-db
    image: clickhouse/clickhouse-server:22.6-alpine
    restart: no
    user: 1000:1000
    volumes:
      - /srv/local/databases/plausible-events/data:/var/lib/clickhouse
      - /srv/local/databases/plausible-events/logs:/var/log/clickhouse-server
      - /srv/local/databases/plausible-events/backups:/backups
      - /srv/local/services/clickhouse/clickhouse-config.xml:/etc/clickhouse-server/config.d/config.xml:ro
      - /srv/local/services/clickhouse/clickhouse-backup_disk.xml:/etc/clickhouse-server/config.d/backup_disk.xml:ro
      - /srv/local/services/clickhouse/clickhouse-user-config.xml:/etc/clickhouse-server/users.d/logging.xml:ro
    ulimits:
      nofile:
        soft: 262144
        hard: 262144
    ports:
      - 7003:8123
    environment:
      - TZ=Europe/Amsterdam

  plausible-app:
    image: plausible/analytics:latest
    container_name: plausible
    restart: no
    user: 1000:1000
    ports:
      - 7004:8000
    command: sh -c "sleep 10 && /entrypoint.sh db createdb && /entrypoint.sh db migrate && /entrypoint.sh db init-admin && /entrypoint.sh run"
    environment:
      - BASE_URL=https://xxx
      - SECRET_KEY_BASE=xxx
      - DATABASE_URL=postgres://xxx:xxxl@xxx:7002/xxx
      - CLICKHOUSE_DATABASE_URL=http://xxx:7003/plausible_events_db
      - BUILD_METADATA={}
      - MAILER_EMAIL=xxx
      - SMTP_HOST_ADDR=xxx
      - SMTP_HOST_PORT=587
      - SMTP_USER_NAME=xxx
      - SMTP_USER_PWD=xxx
      - SMTP_HOST_SSL_ENABLED=false
      - SMTP_RETRIES=2

  backend:
    container_name: pe-backend
    image: rogierlommers/pe-backend
    depends_on:
      - playlist-exchange-db
    ports:
      - "8000:80"
    env_file:
      - .env

  frontend:
    container_name: pe-frontend
    depends_on:
      - backend
    image: rogierlommers/pe-frontend
    ports:
      - "3000:3000"
    env_file:
      - .env

  queue:
    container_name: pe-queue
    image: rabbitmq:3-management
    volumes:
      - /srv/rabbitmq:/var/lib/rabbitmq
    ports:
      - "5672:5672"
      - "15672:15672"
    env_file:
      - .env

  celeryworker:
    container_name: pe-celeryworker
    image: rogierlommers/pe-celeryworker
    depends_on:
      - backend
    env_file:
      - .env

[ Voor 2% gewijzigd door Hero of Time op 28-06-2023 19:58 . Reden: public ipv4 en ipv6 weggehaald :) ]

[Hero of Time]

Sorry voor de dubbele notificatie over edit, maar ik had beide publieke IP adressen niet tegelijk door.

Er lijkt niet direct een reden te zijn voor het niet kunnen verkrijgen van een adres op ens6, maar ik vind de bridge interfaces wel wat verdacht. Wat is de uitvoer van 'brctl'? Als daar ens6 in te vinden is, zal dat mogelijk de oorzaak zijn, je fysieke interface wordt door iets in een bridge gezet.

Wil je handmatig na dit gebeuren ens6 terug krijgen, dan kan je proberen om 'dhclient ens6' uit te voeren. Dit zal een DHCP request starten op de interface. Er is echter geen garantie dat het werkt, maar dat merk je snel genoeg aan de uitvoer.

[smeerbartje]

Hero of Time schreef op woensdag 28 juni 2023 @ 20:01:
Sorry voor de dubbele notificatie over edit, maar ik had beide publieke IP adressen niet tegelijk door.

Er lijkt niet direct een reden te zijn voor het niet kunnen verkrijgen van een adres op ens6, maar ik vind de bridge interfaces wel wat verdacht. Wat is de uitvoer van 'brctl'? Als daar ens6 in te vinden is, zal dat mogelijk de oorzaak zijn, je fysieke interface wordt door iets in een bridge gezet.

Wil je handmatig na dit gebeuren ens6 terug krijgen, dan kan je proberen om 'dhclient ens6' uit te voeren. Dit zal een DHCP request starten op de interface. Er is echter geen garantie dat het werkt, maar dat merk je snel genoeg aan de uitvoer.

Hier de output van brctl show:

code:

rlommers@playlist-exchange [~]$ brctl show
bridge name bridge id       STP enabled interfaces
br-fc0e6199609a     8000.024235bca20d   no      veth0add280
                            veth1e31d28
                            veth5d024a6
                            veth696e571
                            veth836f638
                            veth86a5012
                            vethb60d2ba
                            vethcbbe64e
                            vethe608a0c
docker0     8000.0242b7dc792c   no

Ik zal eens proberen om handmatig een dhcp lease te forceren op het moment dat het weer mis is. Ik ben wel benieuwd of dat dat gaan werken. Zodra het weer voorkomt laat ik het hier weten.

[smeerbartje]

Hero of Time schreef op woensdag 28 juni 2023 @ 20:01:
Sorry voor de dubbele notificatie over edit, maar ik had beide publieke IP adressen niet tegelijk door.

Er lijkt niet direct een reden te zijn voor het niet kunnen verkrijgen van een adres op ens6, maar ik vind de bridge interfaces wel wat verdacht. Wat is de uitvoer van 'brctl'? Als daar ens6 in te vinden is, zal dat mogelijk de oorzaak zijn, je fysieke interface wordt door iets in een bridge gezet.

Wil je handmatig na dit gebeuren ens6 terug krijgen, dan kan je proberen om 'dhclient ens6' uit te voeren. Dit zal een DHCP request starten op de interface. Er is echter geen garantie dat het werkt, maar dat merk je snel genoeg aan de uitvoer.

Nou, het was weer zover.
En wat denk je? OP het moment dat het syteem in dezelfde state zat kon ik met een "dhclient ens6" commando alles weer herstellen. Dan is nu dus de vraag: waarom gaat het syteem in deze staat?

Zou het helpen als ik een static ipadres configureer? Dan heb ik de dhcp server van Strato helemaal niet nodig toch? Zou het aan Strato zelf kunnen liggen?

[Hero of Time]

Het zou aan Strato kunnen liggen, waarbij hun DHCP server te traag is op verzoeken voor verlenging. Maar het systeem vraagt een verlenging aan voordat de lease zou verlopen. Dus als de lease bijvoorbeeld 8 uur is, gaat het dacht ik bij 6 uur al verlenging vragen. Iig ruim van te voren zodat een timeout niet direct een probleem zou worden.

Zag je bijvoorbeeld bij het uitvoeren van 'dhclient ens6' dat het meerdere keren om een adres vroeg met verschillende timeouts tussen de verzoeken? Als het namelijk met de eerste of tweede request al antwoord krijgt, doet de dhcp server iig snel genoeg antwoorden.

Het is daarom interessant om te zien wat er op het systeem in 't algemeen gebeurt. DHCP vernieuwingen zou je in 'journalct' uitvoer moeten zien. Je had eerder een klein stukje geplaatst, maar het probleem komt eerder voor dan de melding 'dhcp timed out'.

[smeerbartje]

Ik ga het nog een paar weken in de gaten houden.
Na m'n vakantie zal ik me hier weer melden .
Dank voor het meedenken!