Another "Redirect loop" error - despite 200 OK in server logs

Help
1

Sorry for asking yet another question about redirect loops. I have read (most of) the relevant posts here but did not find a solution. Since our certificate expires today, I am slowly getting anxious to renew it.

Our server is behind the "AI" firewall of the university that often seems to blocks the first request. Unfortunately, we have no clear information about the firewall and the admins won't help us. Anyhow, we do see requests from letsdebug and also letsencrypt in our sever logs, so things seem to be getting through.

My specific question is about a request that looks good on our side, yet the certbot still displays the infamous "redirect loop detected".

Specifically:

$ certbot renew
...
Cert is due for renewal, auto-renewing...
Plugins selected: Authenticator nginx, Installer nginx
Renewing an existing certificate
Performing the following challenges:
http-01 challenge for <DOMAIN>
Waiting for verification...
Cleaning up challenges
Attempting to renew cert (<DOMAIN>) from /etc/letsencrypt/renewal/<DOMAIN>.conf produced an unexpected error: Failed authorization procedure. <DOMAIN> (http-01): urn:ietf:params:acme:error:connection :: The server could not connect to the client to verify the domain :: <IP>: Fetching http://<DOMAIN>/.well-known/acme-challenge/7D35hkpEHorbyXDpS-htpRR1fpdgK7R1aBbxagj0Uz8: Redirect loop detected. Skipping.
All renewal attempts failed. The following certs could not be renewed:
  /etc/letsencrypt/live/<DOMAIN>/fullchain.pem (failure)

The logs show:
access.log
3.134.78.240 - - [05/Jun/2024:16:17:54 +0900] "GET /.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y HTTP/1.1" 200 87 "-" "Mozilla/5.0 (compatible; Let's Encrypt validation server; +https://www.letsencrypt.org)"

error.log (debugging enabled):

2024/06/05 16:17:54 [debug] 29238#29238: post event 00005609932EBD50
2024/06/05 16:17:54 [debug] 29238#29238: delete posted event 00005609932EBD50
2024/06/05 16:17:54 [debug] 29238#29238: accept on 0.0.0.0:80, ready: 0
2024/06/05 16:17:54 [debug] 29238#29238: posix_memalign: 000056099325C900:512 @16
2024/06/05 16:17:54 [debug] 29238#29238: *1 accept: 3.134.78.240:25790 fd:3
2024/06/05 16:17:54 [debug] 29238#29238: *1 event timer add: 3: 60000:1717571934416
2024/06/05 16:17:54 [debug] 29238#29238: *1 reusable connection: 1
2024/06/05 16:17:54 [debug] 29238#29238: *1 epoll add event: fd:3 op:1 ev:80002001
2024/06/05 16:17:54 [debug] 29238#29238: *1 post event 00005609932EBE70
2024/06/05 16:17:54 [debug] 29238#29238: *1 delete posted event 00005609932EBE70
2024/06/05 16:17:54 [debug] 29238#29238: *1 http wait request handler
2024/06/05 16:17:54 [debug] 29238#29238: *1 malloc: 0000560993264BF0:1024
2024/06/05 16:17:54 [debug] 29238#29238: *1 recv: fd:3 266 of 1024
2024/06/05 16:17:54 [debug] 29238#29238: *1 reusable connection: 0
2024/06/05 16:17:54 [debug] 29238#29238: *1 posix_memalign: 00005609932506D0:4096 @16
2024/06/05 16:17:54 [debug] 29238#29238: *1 http process request line
2024/06/05 16:17:54 [debug] 29238#29238: *1 http request line: "GET /.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y HTTP/1.1"
...
2024/06/05 16:17:54 [debug] 29238#29238: *1 http uri: "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http args: ""
2024/06/05 16:17:54 [debug] 29238#29238: *1 http exten: ""
2024/06/05 16:17:54 [debug] 29238#29238: *1 posix_memalign: 000056099325AF70:4096 @16
2024/06/05 16:17:54 [debug] 29238#29238: *1 http process request header line
2024/06/05 16:17:54 [debug] 29238#29238: *1 http header: "Host: <DOMAIN>"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http header: "User-Agent: Mozilla/5.0 (compatible; Let's Encrypt validation server; +https://www.letsencrypt.org)"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http header: "Accept: */*"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http header: "Accept-Encoding: gzip"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http header: "Connection: close"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http header done
2024/06/05 16:17:54 [debug] 29238#29238: *1 event timer del: 3: 1717571934416
2024/06/05 16:17:54 [debug] 29238#29238: *1 generic phase: 0
2024/06/05 16:17:54 [debug] 29238#29238: *1 rewrite phase: 1
2024/06/05 16:17:54 [debug] 29238#29238: *1 http script regex: "^(/.well-known/acme-challenge/.*)"
2024/06/05 16:17:54 [notice] 29238#29238: *1 "^(/.well-known/acme-challenge/.*)" matches "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y", client: 3.134.78.240, server: <DOMAIN>, request: "GET /.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y HTTP/1.1", host: "<DOMAIN>"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http script capture: "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http script regex end
2024/06/05 16:17:54 [notice] 29238#29238: *1 rewritten data: "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y", args: "", client: 3.134.78.240, server: <DOMAIN>, request: "GET /.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y HTTP/1.1", host: "<DOMAIN>"
2024/06/05 16:17:54 [debug] 29238#29238: *1 test location: "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y"
2024/06/05 16:17:54 [debug] 29238#29238: *1 using configuration "=/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http cl:-1 max:209715200
2024/06/05 16:17:54 [debug] 29238#29238: *1 rewrite phase: 3
2024/06/05 16:17:54 [debug] 29238#29238: *1 http set discard body
2024/06/05 16:17:54 [debug] 29238#29238: *1 xslt filter header
2024/06/05 16:17:54 [debug] 29238#29238: *1 charset: "" > "utf-8"
2024/06/05 16:17:54 [debug] 29238#29238: *1 HTTP/1.1 200 OK
Server: nginx/1.10.3 (Ubuntu)
Date: Wed, 05 Jun 2024 07:17:54 GMT
Content-Type: text/plain; charset=utf-8
Content-Length: 87
Connection: close

2024/06/05 16:17:54 [debug] 29238#29238: *1 write new buf t:1 f:0 000056099325B440, pos 000056099325B440, size: 167 file: 0, size: 0
2024/06/05 16:17:54 [debug] 29238#29238: *1 http write filter: l:0 f:0 s:167
2024/06/05 16:17:54 [debug] 29238#29238: *1 http output filter "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y?"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http copy filter: "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y?"
2024/06/05 16:17:54 [debug] 29238#29238: *1 image filter
2024/06/05 16:17:54 [debug] 29238#29238: *1 xslt filter body
2024/06/05 16:17:54 [debug] 29238#29238: *1 http postpone filter "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y?" 00007FFDA4A30D20
2024/06/05 16:17:54 [debug] 29238#29238: *1 write old buf t:1 f:0 000056099325B440, pos 000056099325B440, size: 167 file: 0, size: 0
2024/06/05 16:17:54 [debug] 29238#29238: *1 write new buf t:0 f:0 0000000000000000, pos 00005609932B7BBB, size: 87 file: 0, size: 0
2024/06/05 16:17:54 [debug] 29238#29238: *1 http write filter: l:1 f:0 s:254
2024/06/05 16:17:54 [debug] 29238#29238: *1 http write filter limit 0
2024/06/05 16:17:54 [debug] 29238#29238: *1 writev: 254 of 254
2024/06/05 16:17:54 [debug] 29238#29238: *1 http write filter 0000000000000000
2024/06/05 16:17:54 [debug] 29238#29238: *1 http copy filter: 0 "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y?"
2024/06/05 16:17:54 [debug] 29238#29238: *1 http finalize request: 0, "/.well-known/acme-challenge/0WbcmqGgckVZhd7WcFdaEvqVSisLxdhs-cOg-R2Jy3Y?" a:1, c:1
2024/06/05 16:17:54 [debug] 29238#29238: *1 event timer add: 3: 5000:1717571879417
2024/06/05 16:17:54 [debug] 29238#29238: *1 http lingering close handler
2024/06/05 16:17:54 [debug] 29238#29238: *1 recv: fd:3 -1 of 4096
2024/06/05 16:17:54 [debug] 29238#29238: *1 recv() not ready (11: Resource temporarily unavailable)
2024/06/05 16:17:54 [debug] 29238#29238: *1 lingering read: -2
2024/06/05 16:17:54 [debug] 29238#29238: *1 event timer: 3, old: 1717571879417, new: 1717571879417
2024/06/05 16:17:54 [debug] 29238#29238: *1 post event 00005609932EBE70
2024/06/05 16:17:54 [debug] 29238#29238: *1 delete posted event 00005609932EBE70
2024/06/05 16:17:54 [debug] 29238#29238: *1 http lingering close handler
2024/06/05 16:17:54 [debug] 29238#29238: *1 recv: fd:3 0 of 4096
2024/06/05 16:17:54 [debug] 29238#29238: *1 lingering read: 0
2024/06/05 16:17:54 [debug] 29238#29238: *1 http request count:1 blk:0
2024/06/05 16:17:54 [debug] 29238#29238: *1 http close request
2024/06/05 16:17:54 [debug] 29238#29238: *1 http log handler
2024/06/05 16:17:54 [debug] 29238#29238: *1 free: 00005609932506D0, unused: 16
2024/06/05 16:17:54 [debug] 29238#29238: *1 free: 000056099325AF70, unused: 2283
2024/06/05 16:17:54 [debug] 29238#29238: *1 close http connection: 3
2024/06/05 16:17:54 [debug] 29238#29238: *1 event timer del: 3: 1717571879417
2024/06/05 16:17:54 [debug] 29238#29238: *1 reusable connection: 0
2024/06/05 16:17:54 [debug] 29238#29238: *1 free: 0000560993264BF0
2024/06/05 16:17:54 [debug] 29238#29238: *1 free: 000056099325C900, unused: 128

I do not understand the renewal failure since our server clearly produced a 200 OK result and sent the file.

Anybody knows what is going on here? Many thanks in advance.

2

3.134.78.240 is likely one of secondary validators: request from main one and other validators are eaten and has no log about it

3 Likes
3

It is a secondary Auth center.

@Barnoid You should see minimum of 4 and probably 5 access log entries for a successful challenge based on today's methods

If you cannot find the cause of the redirect problem we would need the actual domain name to help debug

3 Likes
4

Thank you for your replies. I have "solved" the problem by running certbot manually immediately after letdebug reported success; apparently, this convinced our AI firewall to let all requests from seondary auth centers through.

1 Like
5

I think that was just coincidence. Let's Debug uses the Let's Encrypt Staging system to test. You would get your certs from the production LE system which is a different set of auth servers.

Since your network support won't help you might look at using a DNS Challenge instead. Although, if your uni support won't help with firewall perhaps the DNS is locked out too.

See the Certbot docs for how that works and the DNS providers it supports

3 Likes
6

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.