Initial cert request failing every time (15 failures)

I’m trying to request my first cert (www.jonrowlison.com / jonrowlison.com) and it always fails with the same error at the end of the log: Validation of the required challenges did not complete successfully

It looks like the GUI is attempting to fetch two files from /.well-known/acme-challenge but it is only creating one. The second one is fetchable, but the first one always generates a 404 error because the file doesn’t exist. It does this every time. I’m assuming that both files SHOULD be created by the GUI in the same directory, but it doesn’t and there’s no indication that it’s even trying to.

2020-04-03 17:33:37.612 -05:00 [INF] Certify/4.1.8.0 (Windows; Microsoft Windows NT 6.2.9200.0) 
2020-04-03 17:33:37.612 -05:00 [INF] Beginning Certificate Request Process: jonrowlison using ACME Provider:Certes
2020-04-03 17:33:37.612 -05:00 [INF] Registering Domain Identifiers
2020-04-03 17:33:37.613 -05:00 [ERR] BeginCertificateOrder: creating/retrieving order. Retries remaining:2 
2020-04-03 17:33:38.312 -05:00 [INF] Created ACME Order: https://acme-v02.api.letsencrypt.org/acme/order/81768465/2881532870
2020-04-03 17:33:38.425 -05:00 [INF] Fetching Authorizations.
2020-04-03 17:33:38.993 -05:00 [INF] Got http-01 challenge https://acme-v02.api.letsencrypt.org/acme/chall-v3/3738441053/NRoaAg
2020-04-03 17:33:39.217 -05:00 [INF] Got dns-01 challenge https://acme-v02.api.letsencrypt.org/acme/chall-v3/3738441053/2JYIGA
2020-04-03 17:33:39.668 -05:00 [INF] Got http-01 challenge https://acme-v02.api.letsencrypt.org/acme/chall-v3/3744379927/oRdojA
2020-04-03 17:33:39.904 -05:00 [INF] Got dns-01 challenge https://acme-v02.api.letsencrypt.org/acme/chall-v3/3744379927/ogyuzA
2020-04-03 17:33:41.021 -05:00 [INF] Http Challenge Server process available.
2020-04-03 17:33:41.021 -05:00 [INF] Attempting Domain Validation: jonrowlison.com
2020-04-03 17:33:41.021 -05:00 [INF] Registering and Validating jonrowlison.com 
2020-04-03 17:33:41.021 -05:00 [INF] Performing automated challenge responses (jonrowlison.com)
2020-04-03 17:33:41.021 -05:00 [INF] Preparing challenge response for Let's Encrypt server to check at: http://jonrowlison.com/.well-known/acme-challenge/-EMtfRb7z6Y9KFbp22gc8kp-F_KfBCC8Bo5cMuLN7xA with content -EMtfRb7z6Y9KFbp22gc8kp-F_KfBCC8Bo5cMuLN7xA.dsZO9pFqqSJNI7eB6-WDQyAC58pzR2cCP2w-VynZZTo
2020-04-03 17:33:41.021 -05:00 [INF] If the challenge response file is not accessible at this exact URL the validation will fail and a certificate will not be issued.
2020-04-03 17:33:41.029 -05:00 [INF] Using website path C:\inetpub\sites\jonrowlison
2020-04-03 17:33:41.033 -05:00 [INF] Checking URL is accessible: http://jonrowlison.com/.well-known/acme-challenge/-EMtfRb7z6Y9KFbp22gc8kp-F_KfBCC8Bo5cMuLN7xA [proxyAPI: True, timeout: 5000ms]
2020-04-03 17:33:42.504 -05:00 [INF] URL is accessible. Check passed.
2020-04-03 17:33:42.504 -05:00 [INF] Requesting Validation from Let's Encrypt: jonrowlison.com
2020-04-03 17:33:42.505 -05:00 [INF] Http Challenge Server process available.
2020-04-03 17:33:42.505 -05:00 [INF] Attempting Domain Validation: www.jonrowlison.com
2020-04-03 17:33:42.505 -05:00 [INF] Registering and Validating www.jonrowlison.com 
2020-04-03 17:33:42.505 -05:00 [INF] Performing automated challenge responses (www.jonrowlison.com)
2020-04-03 17:33:42.505 -05:00 [INF] Preparing challenge response for Let's Encrypt server to check at: http://www.jonrowlison.com/.well-known/acme-challenge/gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ with content gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ.dsZO9pFqqSJNI7eB6-WDQyAC58pzR2cCP2w-VynZZTo
2020-04-03 17:33:42.505 -05:00 [INF] If the challenge response file is not accessible at this exact URL the validation will fail and a certificate will not be issued.
2020-04-03 17:33:42.513 -05:00 [INF] Using website path C:\inetpub\sites\jonrowlison
2020-04-03 17:33:42.515 -05:00 [INF] Checking URL is accessible: http://www.jonrowlison.com/.well-known/acme-challenge/gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ [proxyAPI: True, timeout: 5000ms]
2020-04-03 17:33:43.714 -05:00 [INF] URL is accessible. Check passed.
2020-04-03 17:33:43.715 -05:00 [INF] Requesting Validation from Let's Encrypt: www.jonrowlison.com
2020-04-03 17:33:43.715 -05:00 [INF] Attempting Challenge Response Validation for Domain: jonrowlison.com
2020-04-03 17:33:43.715 -05:00 [INF] Registering and Validating jonrowlison.com 
2020-04-03 17:33:43.715 -05:00 [INF] Checking automated challenge response for Domain: jonrowlison.com
2020-04-03 17:33:54.318 -05:00 [INF] Fetching http://jonrowlison.com/.well-known/acme-challenge/-EMtfRb7z6Y9KFbp22gc8kp-F_KfBCC8Bo5cMuLN7xA: Timeout during connect (likely firewall problem)
2020-04-03 17:33:55.821 -05:00 [INF] Validation of the required challenges did not complete successfully. Fetching http://jonrowlison.com/.well-known/acme-challenge/-EMtfRb7z6Y9KFbp22gc8kp-F_KfBCC8Bo5cMuLN7xA: Timeout during connect (likely firewall problem)
2020-04-03 17:33:55.821 -05:00 [INF] Validation of the required challenges did not complete successfully. Fetching http://jonrowlison.com/.well-known/acme-challenge/-EMtfRb7z6Y9KFbp22gc8kp-F_KfBCC8Bo5cMuLN7xA: Timeout during connect (likely firewall problem)

It seems to always create the fetch file for the 2nd URL but never the primary. If I only include the primary and never include a secondary in my cert request, it creates nothing and the whole thing fails.

Here’s the directory CertifyTheWeb is creating. Note it only ever creates one file and that one is successful in the logs. The other file (in this case -EMtfRb7z6Y9KFbp22gc8kp-F_KfBCC8Bo5cMuLN7xA is never created so it will always get a 404.) There shouldn’t be any firewall issues, despite the assertion in the log.

C:\inetpub\sites\jonrowlison\.well-known\acme-challenge>dir
 Volume in drive C has no label.
 Volume Serial Number is 448F-5CEE

 Directory of C:\inetpub\sites\jonrowlison\.well-known\acme-challenge

04/03/2020  05:33 PM    <DIR>          .
04/03/2020  05:33 PM    <DIR>          ..
04/03/2020  11:02 AM                35 configcheck
04/03/2020  05:33 PM                87 gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ
               2 File(s)            122 bytes

You should wrap logs in code/pre-formatted text blocks. It’s easier to read that way and nothing inside is counted as a URL.

```
Log text here… some url like domain.com
```

becomes:

Log text here... some url like domain.com

The file being left behind is interesting because usually they are deleted. Maybe they’re not deleted on failure. My folders only have configcheck in it from using the test button.

The only thing I can think of is maybe IIS is configured in such a way that Certify doesn’t understand that both domains are the same IIS site. If you manually drop a file in that folder, are you able to use a web browser to access it from both normal and WWW domains?

It may be interesting to trace what is happening with ProcMon, if you know how to use it…

Updated with full log text. Thanks for the tip! Let me know if you have any thoughts on what causes the error… :slight_smile:

Yes, I can drop whatever content I want into acme-challenge and grab it via browser. The file that is getting that 404 when Certify The Web tries to hit it just is never being created. And I did try with the directory hard-coded rather than auto-discover. No change.

So I turned on ProcMon and filtered only for “process starts with Certify” and “path starts with c:\inetub”

I got one entry that wasn’t expected… but it would definitely be an issue with Certify if I’m reading this correctly…

6:01:44.1443914 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison	SUCCESS	Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
6:01:44.1444122 PM	CertifySSLManager.Service.exe	9252	QueryNetworkOpenInformationFile	C:\inetpub\sites\jonrowlison	SUCCESS	CreationTime: 5/15/2019 12:07:16 PM, LastAccessTime: 4/3/2020 11:02:03 AM, LastWriteTime: 4/3/2020 11:02:03 AM, ChangeTime: 4/3/2020 11:02:03 AM, AllocationSize: 4096, EndOfFile: 4096, FileAttributes: D
6:01:44.1444206 PM	CertifySSLManager.Service.exe	9252	CloseFile	C:\inetpub\sites\jonrowlison	SUCCESS	
6:01:44.1445622 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge	SUCCESS	Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
6:01:44.1445785 PM	CertifySSLManager.Service.exe	9252	QueryNetworkOpenInformationFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge	SUCCESS	CreationTime: 4/3/2020 11:02:03 AM, LastAccessTime: 4/3/2020 5:58:29 PM, LastWriteTime: 4/3/2020 5:58:29 PM, ChangeTime: 4/3/2020 5:58:29 PM, AllocationSize: 4096, EndOfFile: 4096, FileAttributes: D
6:01:44.1445858 PM	CertifySSLManager.Service.exe	9252	CloseFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge	SUCCESS	
6:01:44.1447424 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	NAME NOT FOUND	Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a
6:01:44.1448281 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Open No Recall, Attributes: n/a, ShareMode: Read, AllocationSize: 0, OpenResult: Created
6:01:44.1449503 PM	CertifySSLManager.Service.exe	9252	WriteFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	Offset: 0, Length: 87, Priority: Normal
6:01:44.1450056 PM	CertifySSLManager.Service.exe	9252	CloseFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	
6:01:45.8170543 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison	SUCCESS	Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
6:01:45.8170729 PM	CertifySSLManager.Service.exe	9252	QueryNetworkOpenInformationFile	C:\inetpub\sites\jonrowlison	SUCCESS	CreationTime: 5/15/2019 12:07:16 PM, LastAccessTime: 4/3/2020 11:02:03 AM, LastWriteTime: 4/3/2020 11:02:03 AM, ChangeTime: 4/3/2020 11:02:03 AM, AllocationSize: 4096, EndOfFile: 4096, FileAttributes: D
6:01:45.8170809 PM	CertifySSLManager.Service.exe	9252	CloseFile	C:\inetpub\sites\jonrowlison	SUCCESS	
6:01:45.8172248 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge	SUCCESS	Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
6:01:45.8172410 PM	CertifySSLManager.Service.exe	9252	QueryNetworkOpenInformationFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge	SUCCESS	CreationTime: 4/3/2020 11:02:03 AM, LastAccessTime: 4/3/2020 6:01:44 PM, LastWriteTime: 4/3/2020 6:01:44 PM, ChangeTime: 4/3/2020 6:01:44 PM, AllocationSize: 4096, EndOfFile: 4096, FileAttributes: D
6:01:45.8172480 PM	CertifySSLManager.Service.exe	9252	CloseFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge	SUCCESS	
6:01:45.8174050 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ	SUCCESS	Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
6:01:45.8174225 PM	CertifySSLManager.Service.exe	9252	QueryNetworkOpenInformationFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ	SUCCESS	CreationTime: 4/3/2020 11:02:13 AM, LastAccessTime: 4/3/2020 5:58:16 PM, LastWriteTime: 4/3/2020 5:58:16 PM, ChangeTime: 4/3/2020 5:58:16 PM, AllocationSize: 88, EndOfFile: 87, FileAttributes: A
6:01:45.8174297 PM	CertifySSLManager.Service.exe	9252	CloseFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ	SUCCESS	
6:01:45.8175237 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ	SUCCESS	Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Open No Recall, Attributes: n/a, ShareMode: Read, AllocationSize: 0, OpenResult: Overwritten
6:01:45.8176277 PM	CertifySSLManager.Service.exe	9252	WriteFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ	SUCCESS	Offset: 0, Length: 87, Priority: Normal
6:01:45.8176715 PM	CertifySSLManager.Service.exe	9252	CloseFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\gWxxCeNRfDNjG5hgwnCqGbsCkWXCYJx5JusVxwXRIgQ	SUCCESS	
6:01:58.3594856 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
6:01:58.3595074 PM	CertifySSLManager.Service.exe	9252	QueryNetworkOpenInformationFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	CreationTime: 4/3/2020 6:01:44 PM, LastAccessTime: 4/3/2020 6:01:44 PM, LastWriteTime: 4/3/2020 6:01:44 PM, ChangeTime: 4/3/2020 6:01:44 PM, AllocationSize: 88, EndOfFile: 87, FileAttributes: A
6:01:58.3595167 PM	CertifySSLManager.Service.exe	9252	CloseFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	
6:01:58.3596057 PM	CertifySSLManager.Service.exe	9252	CreateFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
6:01:58.3596350 PM	CertifySSLManager.Service.exe	9252	QueryAttributeTagFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	Attributes: A, ReparseTag: 0x0
6:01:58.3596456 PM	CertifySSLManager.Service.exe	9252	SetDispositionInformationFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	Delete: True
6:01:58.3596581 PM	CertifySSLManager.Service.exe	9252	CloseFile	C:\inetpub\sites\jonrowlison\.well-known\acme-challenge\3uhHMfm210vaXMfC9m94ORihzY-A0IvT2b4Cvp5doe0	SUCCESS	

This is an interesting one! By default Certify uses a built in http challenge server process (using http.sys) which temporarily spins up during validation, that means IIS doesn’t get used to handle the challenge response (from the file system) unless validation using the challenge server fails (or something else other than IIS is using port 80).

Check first that there are no stuck processes such as Certify.exe that still running, then restart the Certify.Service background service and UI.

I assume you don’t have any other windows ACME/letsencrypt type tools installed which could also be competing for the http://+/.well-known/acme-challenge listener prefix.

Your most recent log complained about timeouts rather than the challenge files returning 404’s.

I didn’t really see much of issue in the ProcMon logs.

It checked if file #1 existed, it did not.
It opened file #1 for writing; wrote 87 bytes; closed the handle.
It checked if file #2 existed, it did; it closed the handle.
It opened file #2 for writing; wrote 87 bytes; closed the handle.
It checked if file #1 existed, it did; it closed the handle.
It opened file #1 for deleting; it set deletion; closed the handle.

So the end result was that at one point, both challenge files existed… but Certify only deleted one of them by the time it finished. It explains what you’re seeing in terms of why you see one file… but it doesn’t explain what your issue really is. It doesn’t appear to be file access trouble.

Just because it’s weird how things play out… try to delete the one it leaves behind and see if it properly cleans up both of them next time. A minor bug, but interesting.

No stuck processes. I’ve actually rebooted the server several times and uninstalled-reinstalled Certify The Web with no change. I have a second web server (the main reason I wanted to try Let’s Encrypt) that is live and has a cert already… when I try to request a cert for that other site, it has the exact same behavior. I’m using jonrowlison.com to track the issue because the two are acting the same way.

I can delete the leftover file that gets stuck in acme-challenge… I can actually delete also the acme-challenge and .well-known directories and everything gets re-created each time I try to do a cert request. But it fails every time on both IIS servers with the same error at the end of the log.

There are no other ACME or Let’s Encrypt products on this server. It’s a brand new Windows 2019 install. I’ve also validated that from 23 points around the world you can get to both www.jonrowlison.com and jonrowlison.com and the firewall is wide-open on port 80 and 443.

I have gone through and deleted files, deleted the directories (acme-challenge and .well-known) many many times. I’ve rebooted the sever many times. I’ve even gone as far as:

uninstall Certify The Web
reboot server
reinstall Certify The Web
reboot server
test

That has the same result. It doesn’t seem there is anything ‘stuck.’ I’ve seen a few posts saying that you can have an issue if an IPv6 AAAA rec isn’t set right… I’ve gone back and checked that there are no IPv6 records in DNS for this site. Certs aren’t a huge issue… I’ve run a PKI for a fortune-100 company for a decade. I’m starting to get discouraged on this one, especially as the multi-domain cert I currently have expires in 2 days and they will renew it for $30.

Jon

The partial challenge files and 404 errors were red herrings. The real issue is the “firewall” error reported.

https://letsdebug.net/jonrowlison.com/119902
https://letsdebug.net/www.jonrowlison.com/119904

Let’s Encrypt servers cannot connect to the website and there’s nothing that Certify or any other ACME program can do about that. I can connect to the website… but using random “is it down” tools have mixed results. 1 of 4 that I tried, failed.

In the end, it is Let’s Encrypt’s servers that matter, not random testing tools.

If you can try the DNS challenge, that may work better. Otherwise, you cannot use Let’s Encrypt until the connectivity issue is solved according to their servers.

2 Likes

As per @jljtgr I can confirm that your site does not allow traffic from some locations. This could be something dynamic you have configured or it could be something your VM host provides. Here is a snapshot using the host-tracker.com port option:

If your domain hosting is with GoDaddy (or another supported DNS provider) you could use the DNS validation option instead of http, or you can figure out how to unblock http requests to your servers.

1 Like

This is a Comcast issue, then. About once every six months, we start to see some remote sites able to get to our servers and some cannot. We usually resolve this by changing MAC addresses, getting a new IP from Comcast and then changing out external DNS to match the new IP we are given. (We have DHCP from them and it’s static in the fact that we always get the same IP for the same MAC.)

Comcast just has this ‘thing’ where the ability of other people to hit our site degenerates over time. It’s the goofiest thing… but I can’t complain to them as we technically aren’t even guaranteed a static IP in the first place so we already have more than they promised us we’d get. :frowning: I’ll re-MAC and then try again later today.

Okay, changed MAC address, rebooted internet router and server one last time. I received a new IP and updated my DNS for the site…

Certify The Web now worked immediately. This was a tough one, as our site resolution is checked from 26 places around the world every few hours and none of our monitors had failed as of Friday when we started the SSL cert process…

By Sunday evening, we had 4 of 26 sites that could no longer reach our site. This is kind of typical with Comcast who over time just seems to “forget” how to or doesn’t update ARP tables or SOMETHING to get traffic to us. It’s frustrating.

Thanks for the help in troubleshooting this. I’m surprised that of all the sites around the world that were failing to reach us that the Certify servers would be some of those few. :frowning:

Jon

If you can I would move to a cloud hosted server/servers perhaps with AWS/azure etc as hosting your own infrastructure on site is far less common now and issues like this are a symptom of that. You can have virtual private links back to your office etc if that’s required for the application to work.