| 27 Nov 2024 |
 hexa | ● acme-lossy.network.service loaded activating start-post start Renew ACME certificate for lossy.network
● acme-musique.lossy.network.service loaded activating start-post start Renew ACME certificate for musique.lossy.network
● acme-paste.lossy.network.service loaded activating start-post start Renew ACME certificate for paste.lossy.network
| 01:49:52 |
| hexa | ● acme-lossy.network.service - Renew ACME certificate for lossy.network
Loaded: loaded (/etc/systemd/system/acme-lossy.network.service; enabled; preset: ignored)
Active: activating (start-post) since Mon 2024-11-25 16:53:59 UTC; 1 day 8h ago
Invocation: d25d36d6c8c04cd7886c1d4bc8d53792
TriggeredBy: ● acme-lossy.network.timer
Main PID: 130913 (code=exited, status=0/SUCCESS); Control PID: 130934 (kia1z8g0zv7w2nd)
IP: 0B in, 0B out
IO: 336K read, 8K written
Tasks: 2 (limit: 4553)
Memory: 1.7M (peak: 19.6M)
CPU: 510ms
CGroup: /system.slice/acme-lossy.network.service
├─130934 /nix/store/0irlcqx2n3qm6b1pc9rsd2i8qpvcccaj-bash-5.2p37/bin/bash /nix/store/kia1z8g0zv7w2ndbr6bf88ybgacjldi1-acme-postrun
└─130936 systemctl reload nginx
| 01:50:23 |
| hexa | Nov 25 16:53:59 juno systemd[1]: Starting Renew ACME certificate for lossy.network...
Nov 25 16:53:59 juno acme-lossy.network-start[130913]: Waiting to acquire lock /run/acme/4.lock
Nov 25 16:53:59 juno acme-lossy.network-start[130913]: Acquired lock /run/acme/4.lock
Nov 25 16:53:59 juno acme-lossy.network-start[130913]: + set -euo pipefail
Nov 25 16:53:59 juno acme-lossy.network-start[130913]: + echo 2692063bb972c5e7df2e
Nov 25 16:53:59 juno acme-lossy.network-start[130913]: + cmp -s domainhash.txt certificates/domainhash.txt
Nov 25 16:53:59 juno acme-lossy.network-start[130913]: + '[' -e certificates/lossy.network.key ']'
Nov 25 16:53:59 juno acme-lossy.network-start[130913]: + '[' -e certificates/lossy.network.crt ']'
Nov 25 16:53:59 juno acme-lossy.network-start[130916]: ++ find accounts -name hexa@darmstadt.ccc.de.key
Nov 25 16:53:59 juno acme-lossy.network-start[130913]: + '[' -n accounts/acme-v02.api.letsencrypt.org/hexa@darmstadt.ccc.de/keys/hexa@darmstadt.ccc.de.key ']'
Nov 25 16:53:59 juno acme-lossy.network-start[130913]: + lego --accept-tos --path . -d lossy.network --email hexa@darmstadt.ccc.de --key-type ec384 --dns rfc2136 --server https://acme-v02.api.letsencrypt.org/directory renew --no-random-sleep --days 30
Nov 25 16:54:00 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:00 [INFO] [lossy.network] acme: Trying renewal with 743 hours remaining
Nov 25 16:54:00 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:00 [INFO] [lossy.network] acme: Obtaining bundled SAN certificate
Nov 25 16:54:00 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:00 [INFO] [lossy.network] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz/1756599672/435404342337
Nov 25 16:54:00 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:00 [INFO] [lossy.network] acme: Could not find solver for: tls-alpn-01
Nov 25 16:54:00 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:00 [INFO] [lossy.network] acme: Could not find solver for: http-01
Nov 25 16:54:00 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:00 [INFO] [lossy.network] acme: use dns-01 solver
Nov 25 16:54:00 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:00 [INFO] [lossy.network] acme: Preparing to solve DNS-01
Nov 25 16:54:00 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:00 [INFO] Found CNAME entry for "_acme-challenge.lossy.network.": "lossy.network._acme.lossy.network."
Nov 25 16:54:01 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:01 [INFO] [lossy.network] acme: Trying to solve DNS-01
Nov 25 16:54:01 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:01 [INFO] Found CNAME entry for "_acme-challenge.lossy.network.": "lossy.network._acme.lossy.network."
Nov 25 16:54:01 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:01 [INFO] [lossy.network] acme: Checking DNS record propagation. [nameservers=127.0.0.1:53,[::1]:53]
Nov 25 16:54:03 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:03 [INFO] Wait for propagation [timeout: 1m0s, interval: 2s]
Nov 25 16:54:09 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:09 [INFO] [lossy.network] The server validated our request
Nov 25 16:54:09 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:09 [INFO] [lossy.network] acme: Cleaning DNS-01 challenge
Nov 25 16:54:09 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:09 [INFO] Found CNAME entry for "_acme-challenge.lossy.network.": "lossy.network._acme.lossy.network."
Nov 25 16:54:09 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:09 [INFO] [lossy.network] acme: Validations succeeded; requesting certificates
Nov 25 16:54:11 juno acme-lossy.network-start[130917]: 2024/11/25 16:54:11 [INFO] [lossy.network] Server responded with a certificate.
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + mv domainhash.txt certificates/
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + chown acme:acme certificates/domainhash.txt certificates/lossy.network.crt certificates/lossy.network.issuer.crt certificates/lossy.network.json certificates/lossy.network.key
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + cmp -s certificates/lossy.network.crt out/fullchain.pem
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + touch out/renewed
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + echo Installing new certificate
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: Installing new certificate
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + cp -vp certificates/lossy.network.crt out/fullchain.pem
Nov 25 16:54:11 juno acme-lossy.network-start[130927]: 'certificates/lossy.network.crt' -> 'out/fullchain.pem'
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + cp -vp certificates/lossy.network.key out/key.pem
Nov 25 16:54:11 juno acme-lossy.network-start[130928]: 'certificates/lossy.network.key' -> 'out/key.pem'
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + cp -vp certificates/lossy.network.issuer.crt out/chain.pem
Nov 25 16:54:11 juno acme-lossy.network-start[130929]: 'certificates/lossy.network.issuer.crt' -> 'out/chain.pem'
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + ln -sf fullchain.pem out/cert.pem
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + cat out/key.pem out/fullchain.pem
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + chmod 640 out/cert.pem out/chain.pem out/fullchain.pem out/full.pem out/key.pem out/renewed
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: + echo 'Releasing lock /run/acme/4.lock'
Nov 25 16:54:11 juno acme-lossy.network-start[130913]: Releasing lock /run/acme/4.lock
| 01:50:47 |
| hexa | ugh, systemctl reload nginx is blocking | 01:51:06 |
| hexa | so all three acme units are stuck at systemctl reload nginx | 01:52:06 |
| hexa | which maps to | 01:52:18 |
| hexa | ExecReload=/nix/store/m489ix7hrxznh7a5fmdsijdlq4x6p5nn-nginx-1.26.2/bin/nginx -c '/nix/store/gnq12cc681ydl6l6bxkh4wrpy1vcan6x-nginx.conf' -t
ExecReload=/nix/store/k48bha2fjqzarg52picsdfwlqx75aqbb-coreutils-9.5/bin/kill -HUP $MAINPID
| 01:52:21 |
| hexa | L1 the config test works | 01:52:34 |
| hexa | and kill -HUP $MAINPID also works 🤔 | 01:53:04 |
| hexa | as root | 01:53:14 |
| hexa | acme post hooks also run as root | 01:53:46 |
| hexa | root 130934 0.0 0.0 6620 3328 ? Ss Nov25 0:00 /nix/store/0irlcqx2n3qm6b1pc9rsd2i8qpvcccaj-bash-5.2p37/bin/bash /nix/store/kia1z8g0zv7w2ndbr6bf88ybgacjldi1-acme-postrun
root 130936 0.0 0.1 18628 7424 ? S Nov25 0:00 \_ systemctl reload nginx
root 131100 0.0 0.0 6620 3328 ? Ss Nov25 0:00 /nix/store/0irlcqx2n3qm6b1pc9rsd2i8qpvcccaj-bash-5.2p37/bin/bash /nix/store/x8pmg6g602b92rrbapxpcmb695n811lb-acme-postrun
root 131103 0.0 0.1 18628 7552 ? S Nov25 0:00 \_ systemctl reload nginx
root 143742 0.0 0.0 6620 3328 ? Ss Nov26 0:00 /nix/store/0irlcqx2n3qm6b1pc9rsd2i8qpvcccaj-bash-5.2p37/bin/bash /nix/store/kr92xf7yisa0236ls1gmacqwapc3zqxz-acme-postrun
root 143745 0.0 0.1 18628 7424 ? S Nov26 0:00 \_ systemctl reload nginx
| 01:53:50 |
| hexa | #!/nix/store/0irlcqx2n3qm6b1pc9rsd2i8qpvcccaj-bash-5.2p37/bin/bash
cd /var/lib/acme/lossy.network
if [ -e renewed ]; then
rm renewed
systemctl reload nginx
fi
| 01:54:14 |
| hexa | renewed does not exist anymore | 01:54:21 |
| hexa | rebooted the machine and reloading works again | 02:02:59 |
| hexa | just wrote this down so maybe if someone else hits it we'll know it is a recurring thing? 😄 | 02:03:15 |
| 28 Nov 2024 |
| hexa | ok, just saw it on the next host 🫠 | 01:40:56 |
 m1cr0man | that's... weird | 22:01:25 |
| m1cr0man | does the nginx service show one of the ExecReload processes as running? | 22:01:49 |
| m1cr0man | I got the --replace-cert-domains --overwrite-domains --force-cert-domains PR merged to lego 😄 once it has been published in a released version, and the setup process refactor has merged, I have a patch set ready to remove the domain hash entirely (test suite remains unchanged + passes, and this won't trigger mass renewal). | 22:12:03 |
 Sandro 🐧 | don't forget to drop it from the test | 22:13:51 |
| Sandro 🐧 | does that mean we renew all certs again ? 😅 | 22:14:09 |
| m1cr0man | No, this does not affect the certDir hash, and thus will not trigger mass renewals.
I'm not sure what you're referring to in the test suite? It does not make reference to the domain hash, and the existing tests are still valid + important. | 22:15:36 |
| m1cr0man | * I got the --replace-cert-domains --overwrite-domains --force-cert-domains PR merged to lego 😄 once it has been published in a released version, and the setup process refactor has merged, I have a patch set ready to remove the domain hash entirely (test suite remains unchanged + passes, and this won't trigger mass renewal). | 23:40:13 |
| 29 Nov 2024 |
| hexa | m1cr0man: https://gist.githubusercontent.com/mweinelt/b27e2353eedc99242a1074a5d2a4e85f/raw/2475ed5c4863f763f8e0e3938dcc2567a633d67d/gistfile1.txt | 02:12:12 |
| hexa | on release-24.11 | 02:12:14 |
| hexa | * on release-24.11 on hydra | 02:12:19 |
| hexa | In reply to @m1cr0man:m1cr0man.com
does the nginx service show one of the ExecReload processes as running? no
● nginx.service - Nginx Web Server
Loaded: loaded (/etc/systemd/system/nginx.service; enabled; preset: ignored)
Active: active (running) since Mon 2024-11-18 02:14:41 UTC; 1 week 4 days ago
Invocation: ae7b61c9c68d4f04bfe52186b992b0b2
Process: 1293 ExecStartPre=/nix/store/0myprdwjj6jjkpd72r1k8qv7fxqnivkp-unit-script-nginx-pre-start/bin/nginx-pre-start (code=exited, status=0/SUCCESS)
Process: 166807 ExecReload=/nix/store/m489ix7hrxznh7a5fmdsijdlq4x6p5nn-nginx-1.26.2/bin/nginx -c /nix/store/8nw18skbb0ic2wznfa652nh0xpdn4s5a-nginx.conf -t (code=exited, status=0/SUCCESS)
Process: 166808 ExecReload=/nix/store/k48bha2fjqzarg52picsdfwlqx75aqbb-coreutils-9.5/bin/kill -HUP $MAINPID (code=exited, status=0/SUCCESS)
Main PID: 1297 (nginx)
IP: 18.4M in, 80.2M out
IO: 21.3M read, 12.7M written
Tasks: 2 (limit: 4553)
Memory: 9.4M (peak: 13.6M)
CPU: 32.430s
CGroup: /system.slice/nginx.service
├─ 1297 "nginx: master process /nix/store/m489ix7hrxznh7a5fmdsijdlq4x6p5nn-nginx-1.26.2/bin/nginx -c /nix/store/8nw18skbb0ic2wznfa652nh0xpdn4s5a-nginx.conf"
└─166814 "nginx: worker process"
| 02:17:04 |
| hexa | it is also not a race, i think | 02:17:19 |
| hexa | because I see it on a third host with just a single unit stuck right now 😩 | 02:17:33 |
