Certificate long time to issue



  • Hello!

    I have setup with standalone and haproxy and rather funny problem.
    It takes more than 6 minutes to issue cert for 6 domain names.

    Relevant log:

    [Tue Feb 12 15:13:25 CET 2019] socat exists=0
    [Tue Feb 12 15:13:25 CET 2019] Le_LocalAddress
    [Tue Feb 12 15:13:25 CET 2019] d='domain.com'
    [Tue Feb 12 15:13:25 CET 2019] Check for domain='domain.com'
    [Tue Feb 12 15:13:25 CET 2019] _currentRoot='no'
    [Tue Feb 12 15:13:25 CET 2019] Standalone mode.
    [Tue Feb 12 15:13:25 CET 2019] OK
    [Tue Feb 12 15:13:25 CET 2019] 9:Le_HTTPPort='80'
    [Tue Feb 12 15:13:25 CET 2019] _checkport='80'
    [Tue Feb 12 15:13:25 CET 2019] _checkaddr
    [Tue Feb 12 15:13:25 CET 2019] ss exists=127
    [Tue Feb 12 15:13:25 CET 2019] netstat exists=0
    [Tue Feb 12 15:13:25 CET 2019] Using: netstat
    [Tue Feb 12 15:14:16 CET 2019] d='www.domain.com'
    [Tue Feb 12 15:14:16 CET 2019] Check for domain='www.domain.com'
    [Tue Feb 12 15:14:16 CET 2019] _currentRoot='no'
    [Tue Feb 12 15:14:16 CET 2019] Standalone mode.
    [Tue Feb 12 15:14:16 CET 2019] OK
    [Tue Feb 12 15:14:16 CET 2019] 9:Le_HTTPPort='80'
    [Tue Feb 12 15:14:16 CET 2019] _checkport='80'
    [Tue Feb 12 15:14:16 CET 2019] _checkaddr
    [Tue Feb 12 15:14:16 CET 2019] ss exists=127
    [Tue Feb 12 15:14:16 CET 2019] netstat exists=0
    [Tue Feb 12 15:14:16 CET 2019] Using: netstat
    

    Problem is that it takes like 50 seconds between those netstat checks.
    Why is that?

    Cert IS issued but it takes really long time.

    Can I do something to speed things up?

    Thanks!



  • @maverick_slo said in Certificate long time to issue:

    Relevant log:

    Not relevant, your log.
    Have a look at the real log file, as indicated at the bottom of the 'green' renewal result log.
    This logs shows much more details and thus probably the reason why it waits.

    Humm : I looked again. You were listing an extract from that file.
    In that case the manual would shed some light ... (== the plugin that uses "nestat" ).

    edit (again) : acme.sh does contain several "pause" situations.
    There are pre-hooks, post-hooks, there could be DNS settle time issues, etc etc.
    I guess the delay you saw is by design.

    Btw : thee couple of minutes happen in the background, totally invisible for the you. You'll be sleeping anyway.



  • Hmm the same thing happens if I use it with standalone but without haproxy.

    Strange is that it worked like a charm few weeks ago.


  • Rebel Alliance Developer Netgate



  • @jimp I know about this method...
    But I would still like to know what changed or why netstat check is taking so long.
    Is this pfsense issue or acme.sh?

    Thanks!


  • Rebel Alliance Developer Netgate

    Hard to tell but since you're using it in an inefficient and unsupported way it could be anything, even haproxy, slowing it down.



  • Ok, if you know by any chance, what are those checks (netstat and check address and port) and what is doing them?
    My plan is to go with dns nsupdate alias mode but I have ton of domains and not much time 😁


  • Rebel Alliance Developer Netgate

    The full log on the filesystem would probably have more to show, but IIRC at that point is when it's listening and waiting for LE to connect and pull the file contents to validate.

    LE has to validate each FQDN in the cert separately.



  • No it does ot listen yet.
    Only after those checks I can see socat bound to port 80 on desired IP.
    After that cert is issued in 4 seconds.

    I`m now almost 100% positive this is ACME issue.



  • @maverick_slo
    How long does it take?: time netstat -an -p tcp | grep LISTEN



  • instant

    While in "wait mode" (nestat) checks before it even starts to listen on 80:

    tcp4       0      0 192.168.166.76.2222    *.*                    LISTEN
    tcp4       0      0 192.168.166.77.443     *.*                    LISTEN
    tcp4       0      0 192.168.166.77.80      *.*                    LISTEN
    tcp4       0      0 127.0.0.1.44443        *.*                    LISTEN
    tcp4       0      0 192.168.166.76.10050   *.*                    LISTEN
    tcp6       0      0 *.44441                *.*                    LISTEN
    tcp4       0      0 *.44441                *.*                    LISTEN
    tcp4       0      0 *.44442                *.*                    LISTEN
    tcp6       0      0 *.44442                *.*                    LISTEN
    tcp4       0      0 192.168.166.76.443     *.*                    LISTEN
    

    And when it listens and actually doing verification:

    tcp4       0      0 *.80                   *.*                    LISTEN
    tcp4       0      0 192.168.166.76.2222    *.*                    LISTEN
    tcp4       0      0 192.168.166.77.443     *.*                    LISTEN
    tcp4       0      0 192.168.166.77.80      *.*                    LISTEN
    tcp4       0      0 127.0.0.1.44443        *.*                    LISTEN
    tcp4       0      0 192.168.166.76.10050   *.*                    LISTEN
    tcp6       0      0 *.44441                *.*                    LISTEN
    tcp4       0      0 *.44441                *.*                    LISTEN
    tcp4       0      0 *.44442                *.*                    LISTEN
    tcp6       0      0 *.44442                *.*                    LISTEN
    tcp4       0      0 192.168.166.76.443     *.*                    LISTEN
    
    

    I`m really out of ideas but unable to upgrade to alpha 😭



  • @piba said in Certificate long time to issue:

    ng does it take?: tim
    Do you suspect haproxy?

    There was 1.8.19 just 2 days ago and already here: https://www.freshports.org/net/haproxy

    :)



  • @maverick_slo said in Certificate long time to issue:

    instant

    I guess i would put several more debug output statements like _debug "Using: netstat" into the acme.sh code surrounding functions that can be 'suspected' they might take a while and are between the parts where the current logs show the time is being spend.. Try and figure out what exact command is really taking the time..



  • Or I could just migrate to DNS verification which is better anyway :)



  • Ummm one more observation.
    Cert was renewed today at 3:16 and it had 14 names in it. It renewed in 180 seconds which is waaaay faster than renew via WebGui.

    So I`m calling it bug or regression or whatever :)

    SYS LOG:
    Feb 14 03:16:00 	php 		Acme, renewing certificate: EXCHANGE_LE
    Feb 14 03:18:37 	php 		Acme, storing new certificate: EXCHANGE_LE
    


  • At home I have same setup 12 domains 30 seconds but I`m on alpha build 2.4.5 :)



  • OK ACME is to blame:

    This code:

    if _exists "netstat"; then
        _debug "Using: netstat"
        if netstat -h 2>&1 | grep "\-p proto" >/dev/null; then
          #for windows version netstat tool
          netstat -an -p tcp | grep "LISTENING" | grep ":$_port "
        else
          if netstat -help 2>&1 | grep "\-p protocol" >/dev/null; then
            netstat -an -p tcp | grep LISTEN | grep ":$_port "
          elif netstat -help 2>&1 | grep -- '-P protocol' >/dev/null; then
            #for solaris
            netstat -an -P tcp | grep "\.$_port " | grep "LISTEN"
          elif netstat -help 2>&1 | grep "\-p" >/dev/null; then
            #for full linux
            netstat -ntpl | grep ":$_port "
          else
            #for busybox (embedded linux; no pid support)
            netstat -ntl 2>/dev/null | grep ":$_port "
          fi
        fi
        return 0
      fi
    

    It executes "if netstat -h 2>&1 | grep "-p proto" >/dev/null; then" which executes netstat -h and this takes long time as it resolves and trying to resolve all IPs :) then when it doesn`t find "-p proto" moves on to next command which is OK for our firewall. I removed first IF after _debug "Using: netstat" and verification is done in like 10 seconds for 12 hosts :)

    So yeah this is bug.

    Code that works:

    if _exists "netstat"; then
        _debug "Using: netstat"
        
        else
          if netstat -help 2>&1 | grep "\-p protocol" >/dev/null; then
            netstat -an -p tcp | grep LISTEN | grep ":$_port "
          elif netstat -help 2>&1 | grep -- '-P protocol' >/dev/null; then
            #for solaris
            netstat -an -P tcp | grep "\.$_port " | grep "LISTEN"
          elif netstat -help 2>&1 | grep "\-p" >/dev/null; then
            #for full linux
            netstat -ntpl | grep ":$_port "
          else
            #for busybox (embedded linux; no pid support)
            netstat -ntl 2>/dev/null | grep ":$_port "
          
        fi
        return 0
      fi
    


  • Time to call Neil ^^



  • ;)
    Reported on github.

    But I still dont understand why this method is not supported or efficient?
    It works really well...


  • Rebel Alliance Developer Netgate

    It's not supported/efficient when hooking to HAProxy because it's redundant. HAProxy can already serve the files, there is no need for ACME to also be a web server involved in the process. ACME can drop the files in a directory, HAproxy can serve them up from there, and it's done. Just needs that python script and settings from the link I shared earlier in the thread.



  • Well we all have our own opinions.
    For me it is simpler:

    1. I don`t need special settings
    2. I don`t need any scripts
    3. I can do it out of the box
    4. Didn`t fail once (except long times because of acme.sh bug)

    If netgate can include that script and integrate it, that would be cool :)


Log in to reply