* When MDMessageCmd for a 'challenge-setup:<type>:<dnsname>' fails (…

…!= 0 exit),

   the renewal process is aborted and an error is reported for the MDomain.
   As discussed in #237, this provides scripts that distribute information
   in a cluster to abort early with bothering an ACME server to validate
   a dns name that will not work. The common retry logic will make another
   attempt in the future, as with other failures.

ChangeLog

@@ -1,3 +1,9 @@
+ * When MDMessageCmd for a 'challenge-setup:<type>:<dnsname>' fails (!= 0 exit),
+   the renewal process is aborted and an error is reported for the MDomain.
+   As discussed in #237, this provides scripts that distribute information
+   in a cluster to abort early with bothering an ACME server to validate
+   a dns name that will not work. The common retry logic will make another
+   attempt in the future, as with other failures.
  * Fixed a bug when adding private key specs to an already working MDomain, see #260.
  * fix time-of-use vs time-of-check when ACME server returned an empty response.
    [kokke <spam@rowdy.dk>]

src/md_acme_authz.c

@@ -275,7 +275,13 @@ static apr_status_t cha_http_01_setup(md_acme_authz_cha_t *cha, md_acme_authz_t
         /* Raise event that challenge data has been set up before we tell the
            ACME server. Clusters might want to distribute it. */
         event = apr_psprintf(p, "challenge-setup:%s:%s", MD_AUTHZ_TYPE_HTTP01, authz->domain);
-        md_result_holler(result, event, p);
+        rv = md_result_raise(result, event, p);
+        if (APR_SUCCESS != rv) {
+            md_log_perror(MD_LOG_MARK, MD_LOG_DEBUG, rv, p,
+                          "%s: event '%s' failed. aborting challenge setup",
+                          authz->domain, event);
+            goto out;
+        }
         /* challenge is setup or was changed from previous data, tell ACME server
          * so it may (re)try verification */        
         authz_req_ctx_init(&ctx, acme, NULL, authz, p);

src/mod_md_drive.c

@@ -137,6 +137,7 @@ static void process_drive_job(md_renew_ctx_t *dctx, md_job_t *job, apr_pool_t *p
             }
 
             if (!job->notified_renewed) {
+                md_job_save(job, result, ptemp);
                 md_job_notify(job, "renewed", result);
             }
         }

test/md_env.py

@@ -1037,19 +1037,23 @@ def get_json_content(self, domain, path, use_https=True, insecure=False,
                          debug_log=True):
         schema = "https" if use_https else "http"
         port = self.https_port if use_https else self.http_port
-        r = self.curl_get(f"{schema}://{domain}:{port}{path}",
-                          insecure=insecure, debug_log=debug_log)
+        url = f"{schema}://{domain}:{port}{path}"
+        r = self.curl_get(url, insecure=insecure, debug_log=debug_log)
+        if r.exit_code != 0:
+            log.error(f"curl get on {url} returned {r.exit_code}"
+                      f"\nstdout: {r.stdout}"
+                      f"\nstderr: {r.stderr}")
         assert r.exit_code == 0, r.stderr
         return r.json
 
     def get_certificate_status(self, domain) -> Dict:
         return self.get_json_content(domain, "/.httpd/certificate-status", insecure=True)
 
-    def get_md_status(self, domain, via_domain=None, use_https=True) -> Dict:
+    def get_md_status(self, domain, via_domain=None, use_https=True, debug_log=False) -> Dict:
         if via_domain is None:
             via_domain = self._default_domain
         return self.get_json_content(via_domain, f"/md-status/{domain}",
-                                     use_https=use_https, debug_log=False)
+                                     use_https=use_https, debug_log=debug_log)
 
     def get_server_status(self, query="/", via_domain=None, use_https=True):
         if via_domain is None:
@@ -1107,12 +1111,12 @@ def await_renewal(self, names, timeout=60):
                 time.sleep(0.1)
         return True
 
-    def await_error(self, domain, timeout=60):
+    def await_error(self, domain, timeout=60, via_domain=None, use_https=True):
         try_until = time.time() + timeout
         while True:
             if time.time() >= try_until:
                 return False
-            md = self.get_md_status(domain)
+            md = self.get_md_status(domain, via_domain=via_domain, use_https=use_https)
             if md:
                 if 'state' in md and md['state'] == MDTestEnv.MD_S_ERROR:
                     return md

test/message.py

@@ -1,4 +1,4 @@
-#!/usr/bin/env python
+#!/usr/bin/env python3
 
 import os
 import sys
@@ -9,16 +9,16 @@ def main(argv):
         cmd = argv[2]
         if 'renewing' != cmd:
             f1 = open(argv[1], 'a+')
-            f1.write('%s\n' % argv)
+            f1.write(f'{argv}\n')
             if 'MD_VERSION' in os.environ:
-                f1.write('MD_VERSION=%s\n' % (os.environ['MD_VERSION']))
+                f1.write(f'MD_VERSION={os.environ["MD_VERSION"]}\n')
             if 'MD_STORE' in os.environ:
-                f1.write('MD_STORE=%s\n' % (os.environ['MD_STORE']))
+                f1.write(f'MD_STORE={os.environ["MD_STORE"]}\n')
             f1.close()
         sys.stderr.write("done, all fine.\n")
         sys.exit(0)
     else:
-        sys.stderr.write("%s without arguments" % (argv[0]))
+        sys.stderr.write(f"{argv[0]} without arguments")
         sys.exit(7)
 
 

test/msg_fail_on.py

@@ -0,0 +1,28 @@
+#!/usr/bin/env python3
+
+import os
+import sys
+
+
+def main(argv):
+    if len(argv) > 3:
+        log = argv[1]
+        fail_on = argv[2]
+        cmd = argv[3]
+        domain = argv[4]
+        if 'renewing' != cmd:
+            f1 = open(log, 'a+')
+            f1.write(f"{[argv[0], log, cmd, domain]}\n")
+            f1.close()
+        if cmd.startswith(fail_on):
+            sys.stderr.write(f"failing on: {cmd}\n")
+            sys.exit(1)
+        sys.stderr.write("done, all fine.\n")
+        sys.exit(0)
+    else:
+        sys.stderr.write("%s without arguments" % (argv[0]))
+        sys.exit(7)
+
+
+if __name__ == "__main__":
+    main(sys.argv)

test/notifail.py

@@ -1,11 +1,10 @@
-#!/usr/bin/env python
+#!/usr/bin/env python3
 
 import sys
 
 
 def main(argv):
     if len(argv) > 1:
-        logfile = argv[1]
         msg = argv[2] if len(argv) > 2 else None
         # fail on later messaging stages, not the initial 'renewing' one.
         # we have test_901_030 that check that later stages are not invoked

test/notify.py

@@ -1,17 +1,16 @@
-#!/usr/bin/env python
+#!/usr/bin/env python3
 
 import sys
 
 
 def main(argv):
     if len(argv) > 2:
-        f1 = open(argv[1], 'a+')
-        f1.write('%s\n' % argv)
-        f1.close()
+        with open(argv[1], 'a+') as f1:
+            f1.write(f"{argv}\n")
         sys.stderr.write("done, all fine.\n")
         sys.exit(0)
     else:
-        sys.stderr.write("%s without arguments" % (argv[0]))
+        sys.stderr.write(f"{argv[0]} without arguments")
         sys.exit(7)
 
 

test/test_901_message.py

@@ -25,9 +25,8 @@ def _class_scope(self, env):
     def _method_scope(self, env, request):
         env.clear_store()
         self.test_domain = env.get_request_domain(request)
-        self.mcmd = ("%s/message.py" % env.test_dir)
-        self.mcmdfail = ("%s/notifail.py" % env.test_dir)
-        self.mlog = ("%s/message.log" % env.gen_dir)
+        self.mcmd = f"{env.test_dir}/message.py"
+        self.mlog = f"{env.gen_dir}/message.log"
         if os.path.isfile(self.mlog):
             os.remove(self.mlog)
 
@@ -53,20 +52,20 @@ def test_901_001(self, env):
 
     # test: signup with configured message cmd that is valid but returns != 0
     def test_901_002(self, env):
-        self.mcmd = ("%s/notifail.py" % env.test_dir)
+        mcmd = f"{env.test_dir}/notifail.py"
         domain = self.test_domain
         domains = [domain, "www." + domain]
         conf = HttpdConf(env)
         conf.add_admin("admin@not-forbidden.org")
-        conf.add_message_cmd("%s %s" % (self.mcmd, self.mlog))
+        conf.add_message_cmd(f"{mcmd} {self.mlog}")
         conf.add_drive_mode("auto")
         conf.add_md(domains)
         conf.add_vhost(domains)
         conf.install()
         env.apache_errors_check()
         env.apache_error_log_clear()
         assert env.apache_restart() == 0
-        assert env.await_completion([domain], restart=False)
+        assert env.await_error(domain)
         stat = env.get_md_status(domain)
         # this command should have failed and logged an error
         assert stat["renewal"]["last"]["problem"] == "urn:org:apache:httpd:log:AH10109:"
@@ -78,13 +77,14 @@ def test_901_003(self, env):
         domains = [domain, "www." + domain]
         conf = HttpdConf(env)
         conf.add_admin("admin@not-forbidden.org")
-        conf.add_message_cmd("%s %s" % (self.mcmd, self.mlog))
+        conf.add_message_cmd(f"{self.mcmd} {self.mlog}")
         conf.add_drive_mode("auto")
         conf.add_md(domains)
         conf.add_vhost(domains)
         conf.install()
         assert env.apache_restart() == 0
         assert env.await_completion([domain], restart=False)
+        time.sleep(1)
         stat = env.get_md_status(domain)
         # this command did not fail and logged itself the correct information
         assert stat["renewal"]["last"]["status"] == 0
@@ -126,7 +126,7 @@ def test_901_004(self, env):
         # force renew
         conf = HttpdConf(env)
         conf.add_admin("admin@not-forbidden.org")
-        conf.add_message_cmd("%s %s" % (self.mcmd, self.mlog))
+        conf.add_message_cmd(f"{self.mcmd} {self.mlog}")
         conf.add("MDRenewWindow 120d")
         conf.add("MDActivationDelay -7d")
         conf.add_md(domains)
@@ -137,11 +137,11 @@ def test_901_004(self, env):
         env.get_md_status(domain)
         assert env.await_file(self.mlog)
         nlines = open(self.mlog).readlines()
-        assert 1 == len(nlines)
-        assert ("['%s', '%s', 'renewed', '%s']" % (self.mcmd, self.mlog, domain)) == nlines[0].strip()
+        assert len(nlines) == 1
+        assert nlines[0].strip() == f"['{self.mcmd}', '{self.mlog}', 'renewed', '{domain}']"
 
     def test_901_010(self, env):
-        # MD with static cert files, lifetime in renewal window, no message about renewal
+        #  MD with static cert files, lifetime in renewal window, no message about renewal
         domain = self.test_domain
         domains = [domain, 'www.%s' % domain]
         testpath = os.path.join(env.gen_dir, 'test_901_010')
@@ -154,10 +154,10 @@ def test_901_010(self, env):
         assert os.path.exists(pkey_file)
         conf = HttpdConf(env)
         conf.add_admin("admin@not-forbidden.org")
-        conf.add_message_cmd("%s %s" % (self.mcmd, self.mlog))
+        conf.add_message_cmd(f"{self.mcmd} {self.mlog}")
         conf.start_md(domains)
-        conf.add("MDCertificateFile %s" % cert_file)
-        conf.add("MDCertificateKeyFile %s" % pkey_file)
+        conf.add(f"MDCertificateFile {cert_file}")
+        conf.add(f"MDCertificateKeyFile {pkey_file}")
         conf.end_md()
         conf.add_vhost(domain)
         conf.install()
@@ -167,7 +167,7 @@ def test_901_010(self, env):
     def test_901_011(self, env):
         # MD with static cert files, lifetime in warn window, check message
         domain = self.test_domain
-        domains = [domain, 'www.%s' % domain]
+        domains = [domain, f'www.{domain}']
         testpath = os.path.join(env.gen_dir, 'test_901_011')
         # cert that is only 10 more days valid
         env.create_self_signed_cert(domains, {"notBefore": -85, "notAfter": 5},
@@ -178,24 +178,24 @@ def test_901_011(self, env):
         assert os.path.exists(pkey_file)
         conf = HttpdConf(env)
         conf.add_admin("admin@not-forbidden.org")
-        conf.add_message_cmd("%s %s" % (self.mcmd, self.mlog))
+        conf.add_message_cmd(f"{self.mcmd} {self.mlog}")
         conf.start_md(domains)
-        conf.add("MDCertificateFile %s" % cert_file)
-        conf.add("MDCertificateKeyFile %s" % pkey_file)
+        conf.add(f"MDCertificateFile {cert_file}")
+        conf.add(f"MDCertificateKeyFile {pkey_file}")
         conf.end_md()
         conf.add_vhost(domain)
         conf.install()
         assert env.apache_restart() == 0
         assert env.await_file(self.mlog)
         nlines = open(self.mlog).readlines()
-        assert 1 == len(nlines)
-        assert ("['%s', '%s', 'expiring', '%s']" % (self.mcmd, self.mlog, domain)) == nlines[0].strip()
+        assert len(nlines) == 1
+        assert nlines[0].strip() == f"['{self.mcmd}', '{self.mlog}', 'expiring', '{domain}']"
         # check that we do not get it resend right away again
         assert env.apache_restart() == 0
         time.sleep(1)
         nlines = open(self.mlog).readlines()
-        assert 1 == len(nlines)
-        assert ("['%s', '%s', 'expiring', '%s']" % (self.mcmd, self.mlog, domain)) == nlines[0].strip()
+        assert len(nlines) == 1
+        assert nlines[0].strip() == f"['{self.mcmd}', '{self.mlog}', 'expiring', '{domain}']"
 
     # MD, check messages from stapling
     @pytest.mark.skipif(MDTestEnv.lacks_ocsp(), reason="no OCSP responder")
@@ -204,7 +204,7 @@ def test_901_020(self, env):
         domains = [domain]
         conf = HttpdConf(env)
         conf.add_admin("admin@not-forbidden.org")
-        conf.add_message_cmd("%s %s" % (self.mcmd, self.mlog))
+        conf.add_message_cmd(f"{self.mcmd} {self.mlog}")
         conf.add_drive_mode("auto")
         conf.add_md(domains)
         conf.add("MDStapling on")
@@ -216,12 +216,15 @@ def test_901_020(self, env):
         assert env.await_file(self.mlog)
         time.sleep(1)
         nlines = open(self.mlog).readlines()
-        assert 4 == len(nlines)
-        assert nlines[0].strip() == ("['%s', '%s', 'challenge-setup:http-01:%s', '%s']"
-                                     % (self.mcmd, self.mlog, domain, domain))
-        assert nlines[1].strip() == ("['%s', '%s', 'renewed', '%s']" % (self.mcmd, self.mlog, domain))
-        assert nlines[2].strip() == ("['%s', '%s', 'installed', '%s']" % (self.mcmd, self.mlog, domain))
-        assert nlines[3].strip() == ("['%s', '%s', 'ocsp-renewed', '%s']" % (self.mcmd, self.mlog, domain))
+        assert len(nlines) == 4
+        assert nlines[0].strip() == \
+               f"['{self.mcmd}', '{self.mlog}', 'challenge-setup:http-01:{domain}', '{domain}']"
+        assert nlines[1].strip() == \
+               f"['{self.mcmd}', '{self.mlog}', 'renewed', '{domain}']"
+        assert nlines[2].strip() == \
+               f"['{self.mcmd}', '{self.mlog}', 'installed', '{domain}']"
+        assert nlines[3].strip() == \
+               f"['{self.mcmd}', '{self.mlog}', 'ocsp-renewed', '{domain}']"
 
     # test: while testing gh issue #146, it was noted that a failed renew notification never
     # resets the MD activity.
@@ -239,7 +242,7 @@ def test_901_030(self, env):
         # set the warn window that triggers right away and a failing message command
         conf = HttpdConf(env)
         conf.add_admin("admin@not-forbidden.org")
-        conf.add_message_cmd("%s %s" % (self.mcmdfail, self.mlog))
+        conf.add_message_cmd(f"{env.test_dir}/notifail.py {self.mlog}")
         conf.add_md(domains)
         conf.add("""
             MDWarnWindow 100d
@@ -263,7 +266,7 @@ def test_901_030(self, env):
         # reconfigure to a working notification command and restart
         conf = HttpdConf(env)
         conf.add_admin("admin@not-forbidden.org")
-        conf.add_message_cmd("%s %s" % (self.mcmd, self.mlog))
+        conf.add_message_cmd(f"{self.mcmd} {self.mlog}")
         conf.add_md(domains)
         conf.add("""
             MDWarnWindow 100d
@@ -274,10 +277,37 @@ def test_901_030(self, env):
         assert env.await_file(self.mlog)
         # we see the notification logged by the command
         nlines = open(self.mlog).readlines()
-        assert 1 == len(nlines)
-        assert ("['%s', '%s', 'expiring', '%s']" % (self.mcmd, self.mlog, domain)) == nlines[0].strip()
+        assert len(nlines) == 1
+        assert nlines[0].strip() == f"['{self.mcmd}', '{self.mlog}', 'expiring', '{domain}']"
         # the error needs to be gone
         assert env.await_file(env.store_staged_file(domain, 'job.json'))
         with open(env.store_staged_file(domain, 'job.json')) as f:
             job = json.load(f)
             assert job["errors"] == 0
+
+    # MD, check a failed challenge setup
+    def test_901_040(self, env):
+        domain = self.test_domain
+        domains = [domain]
+        conf = HttpdConf(env)
+        conf.add_admin("admin@not-forbidden.org")
+        mcmd = f"{env.test_dir}/msg_fail_on.py"
+        conf.add_message_cmd(f"{mcmd} {self.mlog} challenge-setup")
+        conf.add_drive_mode("auto")
+        conf.add_md(domains)
+        conf.add_vhost(domains)
+        conf.install()
+        assert env.apache_restart() == 0
+        assert env.await_error(domain)
+        assert env.await_file(self.mlog)
+        time.sleep(1)
+        nlines = open(self.mlog).readlines()
+        assert len(nlines) == 2
+        assert nlines[0].strip() == \
+               f"['{mcmd}', '{self.mlog}', 'challenge-setup:http-01:{domain}', '{domain}']"
+        assert nlines[1].strip() == \
+               f"['{mcmd}', '{self.mlog}', 'errored', '{domain}']"
+        stat = env.get_md_status(domain)
+        # this command should have failed and logged an error
+        assert stat["renewal"]["last"]["problem"] == "challenge-setup-failure"
+