hanging in fail-loop

[ensonic]

I've switched the dns layout of a project. I can check all subdomains are resolved (using dig). Still getting cert for the new subdomains loops since hours with no noticeable progress. I already have shutdown everything and deleted the keypair to restart with a fresh quota and that does not seem to be the issue.
Here is a bit of the log:

{"@timestamp":"2018-03-23T16:19:51.037+00:00","@version":1,"message":"Service letsencrypt-dummy requesting certificates: [ensonic.dev.cloudrobotics.com, registry.core-grpc.ensonic.dev.cloudrobotics.com, www.ensonic.dev.cloudrobotics.com, ws.ensonic.dev.cloudrobotics.com]","logger_name":"in.tazj.k8s.letsencrypt.kubernetes.ServiceManager","thread_name":"Thread-28","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:19:51.553+00:00","@version":1,"message":"Using existing ACME user: https://acme-v01.api.letsencrypt.org/acme/reg/YYYYYYYYY","logger_name":"in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler","thread_name":"Thread-28","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:19:51.898+00:00","@version":1,"message":"Issuing new challenge for www.ensonic.dev.cloudrobotics.com","logger_name":"in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler","thread_name":"Thread-28","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:19:52.184+00:00","@version":1,"message":"Issuing new challenge for ensonic.dev.cloudrobotics.com","logger_name":"in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler","thread_name":"ForkJoinPool.commonPool-worker-1","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:19:52.478+00:00","@version":1,"message":"Issuing new challenge for registry.core-grpc.ensonic.dev.cloudrobotics.com","logger_name":"in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:19:52.717+00:00","@version":1,"message":"Waiting for change in zone external-dns to finish. This may take some time.","logger_name":"in.tazj.k8s.letsencrypt.acme.CloudDnsResponder","thread_name":"Thread-28","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:19:52.765+00:00","@version":1,"message":"Issuing new challenge for ws.ensonic.dev.cloudrobotics.com","logger_name":"in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler","thread_name":"ForkJoinPool.commonPool-worker-0","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:19:53.002+00:00","@version":1,"message":"Waiting for change in zone external-dns to finish. This may take some time.","logger_name":"in.tazj.k8s.letsencrypt.acme.CloudDnsResponder","thread_name":"ForkJoinPool.commonPool-worker-1","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:19:54.261+00:00","@version":1,"message":"Waiting for change in zone external-dns to finish. This may take some time.","logger_name":"in.tazj.k8s.letsencrypt.acme.CloudDnsResponder","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:19:55.242+00:00","@version":1,"message":"Waiting for change in zone external-dns to finish. This may take some time.","logger_name":"in.tazj.k8s.letsencrypt.acme.CloudDnsResponder","thread_name":"ForkJoinPool.commonPool-worker-0","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:21:33.680+00:00","@version":1,"message":"Waiting for DNS record '_acme-challenge.www.ensonic.dev.cloudrobotics.com' update","logger_name":"in.tazj.k8s.letsencrypt.util.DnsRecordObserver","thread_name":"Thread-28","level":"INFO","level_value":20000}
Exception in thread "Thread-28" java.lang.NullPointerException
	at com.google.common.collect.ImmutableList.copyOf(ImmutableList.java:267)
	at in.tazj.k8s.letsencrypt.util.DnsRecordObserver.findAuthoritativeNameservers(DnsRecordObserver.kt:76)
	at in.tazj.k8s.letsencrypt.util.DnsRecordObserver.observeDns(DnsRecordObserver.kt:24)
	at in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler.prepareDnsChallenge(CertificateRequestHandler.kt:179)
	at in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler.authorizeDomain(CertificateRequestHandler.kt:77)
	at in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler.access$authorizeDomain(CertificateRequestHandler.kt:27)
	at in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler$requestCertificate$1.accept(CertificateRequestHandler.kt:41)
	at in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler$requestCertificate$1.accept(CertificateRequestHandler.kt:27)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
	at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1374)
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481)
	at java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:291)
	at java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:731)
	at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
	at java.util.concurrent.ForkJoinTask.doInvoke(ForkJoinTask.java:401)
	at java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:734)
	at java.util.stream.ForEachOps$ForEachOp.evaluateParallel(ForEachOps.java:160)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateParallel(ForEachOps.java:174)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233)
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:418)
	at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:583)
	at in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler.requestCertificate(CertificateRequestHandler.kt:41)
	at in.tazj.k8s.letsencrypt.kubernetes.ServiceManager.handleCertificateRequest(ServiceManager.kt:64)
	at in.tazj.k8s.letsencrypt.kubernetes.ServiceManager.access$handleCertificateRequest(ServiceManager.kt:20)
	at in.tazj.k8s.letsencrypt.kubernetes.ServiceManager$reconcileService$1.run(ServiceManager.kt:45)
	at java.lang.Thread.run(Thread.java:745)
{"@timestamp":"2018-03-23T16:21:35.366+00:00","@version":1,"message":"Waiting for DNS record '_acme-challenge.ensonic.dev.cloudrobotics.com' update","logger_name":"in.tazj.k8s.letsencrypt.util.DnsRecordObserver","thread_name":"ForkJoinPool.commonPool-worker-1","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:21:35.920+00:00","@version":1,"message":"Waiting for DNS record '_acme-challenge.registry.core-grpc.ensonic.dev.cloudrobotics.com' update","logger_name":"in.tazj.k8s.letsencrypt.util.DnsRecordObserver","thread_name":"ForkJoinPool.commonPool-worker-3","level":"INFO","level_value":20000}
{"@timestamp":"2018-03-23T16:21:36.195+00:00","@version":1,"message":"Waiting for DNS record '_acme-challenge.ws.ensonic.dev.cloudrobotics.com' update","logger_name":"in.tazj.k8s.letsencrypt.util.DnsRecordObserver","thread_name":"ForkJoinPool.commonPool-worker-0","level":"INFO","level_value":20000}

FYI: earlier in the log I can see

"@timestamp":"2018-03-23T15:21:22.118+00:00","@version":1,"message":"Created new ACME user, URI: https://acme-v01.api.letsencrypt.org/acme/reg/XXXXX","logger_name":"in.tazj.k8s.letsencrypt.acme.CertificateRequestHandler","thread_name":"Thread-2","level":"INFO","level_value":20000}

I can also see the acme challenges using:

dig -t txt _acme-challenge.ensonic.dev.cloudrobotics.com. +short

[ensonic]

This did not finish over the weekend. I just started over and now it just worked (TM). Feel free to close it if you can't spot anything.

[tazjin]

Hey,

not sure about the cause, but the issue itself was probably one of the ones fixed in a recent PR. I should cut a release, as someone pointed out on an issue here recently :)