plugins icon indicating copy to clipboard operation
plugins copied to clipboard

security/os-acme-client: Reducing the renewal interval results in auto renewal dns01 validation failed errors

Open coderjoe opened this issue 4 months ago • 7 comments

Important notices Before you add a new report, we ask you kindly to acknowledge the following:

  • [x] I have read the contributing guide lines at https://github.com/opnsense/plugins/blob/master/CONTRIBUTING.md
  • [x] I have searched the existing issues, open and closed, and I'm convinced that mine is new.
  • [x] The title contains the plugin to which this issue belongs

Describe the bug When a certificate is issued at a higher renewal interval, but the renewal interval is reduced then the os-acme-client auto renewal cron job will attempt to renew but the acme.sh project will throw an error that the certificate is not yet ready for renewal.

This will happen for every cron run until the original renewal date is passed.

To Reproduce Steps to reproduce the behavior:

  1. Go to services -> acme client -> settings
  2. Click the update schedule tab
  3. Verify that the Renew ACME certificates cron job is running at least once a day
  4. Go to services -> acme client -> accounts
  5. Ensure that a staging environment is configured and registered
  6. Go to services -> acme client -> challenge types
  7. Set up a dns01 challenge type to use
  8. Go to services -> acme client -> certificates
  9. Click + to add a new certificate
  10. Pick a common name
  11. Set ACME account to staging
  12. Set challenge type to the previously created dns01 challenge type
  13. Ensure Auto Renewal is checked
  14. Set renewal interval to 3 days
  15. Click save
  16. Click the to "issue or renew certificate" on your certificate
  17. Once issued click the pencil icon to edit the certificate
  18. Change the renewal interval to 1 day
  19. Click save but DO NOT issue or renew the certificate
  20. Wait for the cron job to run
  21. Check the system log files and note that you errors similar to: AcmeClient: domain validation failed (dns01) and `
  22. Check the system log and note that you get an error similar to AcmeClient: AcmeClient: The shell command returned exit code '2'
  23. Check the ACME Log and note the log similar to:
Renewing: '<domain name>'
Add '--force' to force renewal.
Skipping. Next renewal time is: <timestamp>

Expected behavior

One of:

  1. skipped renewals should be reported as such and not be considered an error
  2. when the cron job runs, if the renewal interval has changed then the cert should be force renewed.
  3. when the cron job runs, if the renewal interval is less than the prior interval, then the cert should be force renewed
  4. when the renewal interval is changed, the system should strongly suggest the user force issue or renewal int he UI to avoid issues with automatic renewal.

Screenshots none

Relevant log files Logs here: https://gist.github.com/coderjoe/c6b01e2db8bc68072bd50e58ead27df8

Additional context I think this is related to the os-acme-client using any non-zero numeric value from a run to represent failure. But the acme.sh project uses an exit code of $RENEW_SKIP which evaluates to 2 to represent a skipped renewal.

Environment OPNsense 25.7.1_1-amd64

coderjoe avatar Aug 22 '25 02:08 coderjoe

Please provide the full (untrimmed) logs.

fraenki avatar Aug 26 '25 09:08 fraenki

@fraenki the gist is nearly the entire log (edit: for the particular certificate and cron job run) in normal mode with some personal data snipped out.

I'm happy to rerun the test in a debug mode if you would like to get more logs. Which debug mode would you prefer?

Alternatively you should be able to reproduce this issue with the instructions above.

I understand the full instructions are long so I can sum them up as:

  1. Use dns validation
  2. Issue a cert with a renewal interval of at least 3 days or more
  3. Issue the cert
  4. Edit the cert and reduce the renewal interval to 1 day
  5. Save but do not issue or renew.
  6. Wait one day for auto renew to trigger and the errors will start showing up in the log for each auto renewal

coderjoe avatar Aug 26 '25 14:08 coderjoe

Please post full logs with debug3 enabled. Thanks! (Of course, feel free to redact personal information.)

fraenki avatar Aug 26 '25 14:08 fraenki

Ok let me set this up in a VM and duplicate the issue so I can get you a full log without exposing all of my other managed certs and domains.

It might take me a week or two to get the time + the 2-3 days to duplicate the issue.

Thanks in advance for your patience. :)

coderjoe avatar Aug 26 '25 16:08 coderjoe

@fraenki

I've set up a fresh install of opnsense 25.7 I've installed the community os-acme-client plugin I've set debug level 3

Unfortunately I think I'm running into a separate bug. On my fresh install acme.sh never outputs logs to the ACME Logs tab in the UI. I can't seem to find any of the debug logs anywhere. I even checked the old /var/log/acme.sh.log file but it looks like that was removed as of https://github.com/fraenki/plugins/commit/1e0e4dc323098531973f23b1271d5f8962819517

Symptoms look identical to https://github.com/opnsense/plugins/issues/2227 Should I open a separate ticket for that regression?

I can't generate any logs in the mean time.

coderjoe avatar Aug 28 '25 02:08 coderjoe

I figured i'd get ahead of the 2029 47 day cert lifespan now and dropped my cert from 60 to 30 day renewal and saw the same problem. Here's my acmeclient.log with debug3

<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 32290 - [meta sequenceId="26"] [Mon Nov 10 23:17:39 CST 2025] LE_WORKING_DIR='/var/etc/acme-client/home'
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 36788 - [meta sequenceId="27"] [Mon Nov 10 23:17:39 CST 2025] Using server: https://acme-v02.api.letsencrypt.org/directory
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 41735 - [meta sequenceId="28"] [Mon Nov 10 23:17:39 CST 2025] Running cmd: renew
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 45873 - [meta sequenceId="29"] [Mon Nov 10 23:17:39 CST 2025] _renewServer='https://acme-v02.api.letsencrypt.org/directory'
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 49548 - [meta sequenceId="30"] [Mon Nov 10 23:17:39 CST 2025] Using config home: /var/etc/acme-client/home
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 53548 - [meta sequenceId="31"] [Mon Nov 10 23:17:39 CST 2025] ACCOUNT_CONF_PATH='/var/etc/acme-client/accounts/6033188831b9f7.13537210_prod/account.conf'
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 58488 - [meta sequenceId="32"] [Mon Nov 10 23:17:39 CST 2025] ACME_DIRECTORY='https://acme-v02.api.letsencrypt.org/directory'
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 64600 - [meta sequenceId="33"] [Mon Nov 10 23:17:39 CST 2025] _ACME_SERVER_HOST='acme-v02.api.letsencrypt.org'
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 69306 - [meta sequenceId="34"] [Mon Nov 10 23:17:39 CST 2025] _ACME_SERVER_PATH='directory'
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 73681 - [meta sequenceId="35"] [Mon Nov 10 23:17:39 CST 2025] CA_CONF='/var/etc/acme-client/home/ca/acme-v02.api.letsencrypt.org/directory/ca.conf'
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 76330 - [meta sequenceId="36"] [Mon Nov 10 23:17:39 CST 2025] DOMAIN_PATH='/var/etc/acme-client/cert-home/63842441b1fd91.02012329/<hostname>'
<14>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 79859 - [meta sequenceId="37"] [Mon Nov 10 23:17:39 CST 2025] Renewing: '<hostname>'
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 83721 - [meta sequenceId="38"] [Mon Nov 10 23:17:39 CST 2025] OK
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 90374 - [meta sequenceId="39"] [Mon Nov 10 23:17:39 CST 2025] 15:Le_RenewalDays='30'
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 94415 - [meta sequenceId="40"] [Mon Nov 10 23:17:39 CST 2025] Le_API='https://acme-v02.api.letsencrypt.org/directory'
<14>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 98580 - [meta sequenceId="41"] [Mon Nov 10 23:17:39 CST 2025] Renewing using Le_API=https://acme-v02.api.letsencrypt.org/directory
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 2085 - [meta sequenceId="42"] [Mon Nov 10 23:17:39 CST 2025] initpath again.
<15>1 2025-11-10T23:17:39-06:00 <hostname> acme.sh 6301 - [meta sequenceId="43"] [Mon Nov 10 23:17:39 CST 2025] Using config home: /var/etc/acme-client/home
<15>1 2025-11-10T23:17:40-06:00 <hostname> acme.sh 10169 - [meta sequenceId="44"] [Mon Nov 10 23:17:40 CST 2025] ACCOUNT_CONF_PATH='/var/etc/acme-client/accounts/6033188831b9f7.13537210_prod/account.conf'
<15>1 2025-11-10T23:17:40-06:00 <hostname> acme.sh 13469 - [meta sequenceId="45"] [Mon Nov 10 23:17:40 CST 2025] ACME_DIRECTORY='https://acme-v02.api.letsencrypt.org/directory'
<15>1 2025-11-10T23:17:40-06:00 <hostname> acme.sh 19822 - [meta sequenceId="46"] [Mon Nov 10 23:17:40 CST 2025] _ACME_SERVER_HOST='acme-v02.api.letsencrypt.org'
<15>1 2025-11-10T23:17:40-06:00 <hostname> acme.sh 25074 - [meta sequenceId="47"] [Mon Nov 10 23:17:40 CST 2025] _ACME_SERVER_PATH='directory'
<15>1 2025-11-10T23:17:40-06:00 <hostname> acme.sh 28693 - [meta sequenceId="48"] [Mon Nov 10 23:17:40 CST 2025] CA_CONF='/var/etc/acme-client/home/ca/acme-v02.api.letsencrypt.org/directory/ca.conf'
<14>1 2025-11-10T23:17:40-06:00 <hostname> acme.sh 32516 - [meta sequenceId="49"] [Mon Nov 10 23:17:40 CST 2025] Skipping. Next renewal time is: 2025-11-27T05:04:48Z
<14>1 2025-11-10T23:17:40-06:00 <hostname> acme.sh 35748 - [meta sequenceId="50"] [Mon Nov 10 23:17:40 CST 2025] Add '--force' to force renewal. 

Here's the system.log showing the acme call resulting in a validation failure but it seems to be due to the previous expiration date not reached yet

<173>1 2025-11-10T23:17:39-06:00 <hostname> config 41847 - [meta sequenceId="12"] AcmeClient: certificate must be issued/renewed: <hostname>
<173>1 2025-11-10T23:17:39-06:00 <hostname> config 41847 - [meta sequenceId="13"] AcmeClient: renew certificate: <hostname>
<173>1 2025-11-10T23:17:39-06:00 <hostname> config 41847 - [meta sequenceId="14"] AcmeClient: using CA: letsencrypt
<173>1 2025-11-10T23:17:39-06:00 <hostname> config 41847 - [meta sequenceId="15"] AcmeClient: account is registered: <account>
<173>1 2025-11-10T23:17:39-06:00 <hostname> config 41847 - [meta sequenceId="16"] AcmeClient: using challenge type: <challenge>
<173>1 2025-11-10T23:17:39-06:00 <hostname> config 41847 - [meta sequenceId="17"] AcmeClient: running acme.sh command: /usr/local/sbin/acme.sh --renew --syslog 9 --debug 3 --server 'letsencrypt'
 --dns 'dns_cf' --dnssleep '120' --home '/var/etc/acme-client/home' --cert-home '/var/etc/acme-client/cert-home/<certdir>' --certpath '/var/etc/acme-client/certs/<certdir>/cert.pem' --
keypath '/var/etc/acme-client/keys/<certdir>/private.key' --capath '/var/etc/acme-client/certs/<certdir>/chain.pem' --fullchainpath '/var/etc/acme-client/certs/<certdir>/
fullchain.pem' --domain '<hostname>' --days '30'   --keylength '4096' --accountconf '/var/etc/acme-client/accounts/<accountdir>/account.conf'
<173>1 2025-11-10T23:17:40-06:00 <hostname> config 41847 - [meta sequenceId="18"] AcmeClient: AcmeClient: The shell command returned exit code '2': '/usr/local/sbin/acme.sh --renew --syslog 9 --debug 3 --server 'letsencrypt' --dns 'dns_cf' --dnssleep '120' --home '/var/etc/acme-client/home' --cert-home '/var/etc/acme-client/cert-home/<certdir>' --certpath '/var/etc/acme-client/certs/<certdir>/cert.pem' --keypath '/var/etc/acme-client/keys/<certdir>/private.key' --capath '/var/etc/acme-client/certs/<certdir>/chain.pem' --fullchainpath '/var/etc/acme-client/certs/<certdir>/fullchain.pem' --domain '<hostname>' --days '30'   --keylength '4096' --accountconf '/var/etc/acme-client/accounts/<accountdir>/account.conf''
<171>1 2025-11-10T23:17:40-06:00 <hostname> config 41847 - [meta sequenceId="19"] AcmeClient: domain validation failed (dns01)
<171>1 2025-11-10T23:17:40-06:00 <hostname> config 41847 - [meta sequenceId="20"] AcmeClient: validation for certificate failed: <hostname>

wangmaster avatar Nov 11 '25 05:11 wangmaster

That does look incredibly similar to what I experienced and haven't been able to duplicate on a fresh install.

coderjoe avatar Nov 13 '25 02:11 coderjoe