caddyserver/certmagic

Port usage contradiction error

oliverpool opened this issue ยท 6 comments

What would you like to have changed?

I have seen the message below in my logs:

[WARNING] OS reports a contradiction: listen tcp :443: bind: address already in use - but we cannot connect to it, with this error: dial tcp :443: connect: connection refused; continuing anyway ๐Ÿคž (I don't know what causes this... if you do, please help?)

certmagic/solvers.go

Lines 385 to 389 in 03d0645

if strings.Contains(listenErr.Error(), "address already in use") ||
strings.Contains(listenErr.Error(), "one usage of each socket address") {
log.Printf("[WARNING] OS reports a contradiction: %v - but we cannot connect to it, with this error: %v; continuing anyway ๐Ÿคž", listenErr, connectErr)
return nil, nil
}

Here is how I used the library:

		// SETUP TLS
		certmagic.DefaultACME.Email = "redacted@example.org"
		certmagic.DefaultACME.Agreed = true
		certmagic.DefaultACME.DisableHTTPChallenge = true

		// bugfix will come here

		certConfig := certmagic.NewDefault()
		certConfig.Storage = &certmagic.FileStorage{
			Path: stateDir + ".certmagic",
		}
		tlsConfig := certConfig.TLSConfig()
		tlsConfig.NextProtos = append([]string{"h2", "http/1.1"}, tlsConfig.NextProtos...)

		ln, err = tls.Listen("tcp", addr, tlsConfig)
		if err != nil {
			return err
		}

		if err := certConfig.ManageAsync(ctx, domains); err != nil { // async to prevent systemd restart
			return fmt.Errorf("could not manage TLS certificates: %v", err)
		}

However the addr variable is no just a port (:443), but a full IPv6 address ([1234::1]:443).

So it probably went like this:

  • my program binds to [1234::1]:443
  • certmagic tries to dial :443: no reply since I am not listening everywhere
  • certmagic tries to bind :443: failure since this port is not free for [1234::1]

In my case, the solution was to adjust certmagic.DefaultACME.ListenHost

		certmagic.DefaultACME.DisableHTTPChallenge = true
		certmagic.DefaultACME.ListenHost, _, err = net.SplitHostPort(addr)
		if err != nil {
			return err
		}
		logger.Log("listen-host", certmagic.DefaultACME.ListenHost)

Maybe this information can help craft a better error message?

mholt commented

Huh, interesting -- thanks for the info.

What OS are you using?

I used to be pretty sure that you could bind to both :443 and host:443, as the OS would choose the more specific interface... ๐Ÿค”

What OS are you using?

Debian GNU/Linux 11 (bullseye)
Linux debian 5.10.0-18-amd64

Output of sudo netstat -tnlp | grep :443:

tcp        0      0 167.235.XXX.XXX:443     0.0.0.0:*               LISTEN      3638206/snid
tcp6       0      0 1234:4567:::443 :::*                    LISTEN      3638173/redacted

I have snid listening on the IPv4 and my program on IPv6.

Please find below a minimal reproducer:

https://git.sr.ht/~oliverpool/exp/tree/main/item/mre/certmagic/main.go

package main

import (
	"errors"
	"fmt"
	"log"
	"net"
	"strings"
)

func main() {
	if err := run(); err != nil {
		log.Fatal(err)
	}
}
func run() error {
	ip, err := GetOutboundIP()
	if err != nil {
		return err
	}

	port := "1965"

	serverLn, err := net.Listen("tcp", net.JoinHostPort(ip, port))
	if err != nil {
		return err
	}
	defer serverLn.Close()
	fmt.Println("own server listening on", serverLn.Addr().String())

	// certmagic logic
	addr := ":" + port
	ln, listenErr := net.Listen("tcp", addr)
	if listenErr == nil {
		ln.Close()
		return errors.New("certmagic: could listen on " + addr)
	}
	fmt.Println("certmagic: could not listen on", addr, listenErr)

	conn, connectErr := net.Dial("tcp", addr)
	if connectErr == nil {
		conn.Close()
		return errors.New("certmagic: could dial " + addr)
	}
	fmt.Println("certmagic: could not dial", addr, connectErr)

	if strings.Contains(listenErr.Error(), "address already in use") {
		fmt.Printf("[WARNING] OS reports a contradiction: %v - but we cannot connect to it, with this error: %v; continuing anyway ๐Ÿคž\n", listenErr, connectErr)
	}
	return nil
}

// Get preferred outbound ip of this machine
// adapted from https://stackoverflow.com/a/37382208/3207406
func GetOutboundIP() (string, error) {
	conn, err := net.Dial("udp", "8.8.8.8:80")
	if err != nil {
		return "", err
	}
	defer conn.Close()

	localAddr := conn.LocalAddr().(*net.UDPAddr)

	return localAddr.IP.String(), nil
}

Output on my machine:

own server listening on 192.168.179.4:1965
certmagic: could not listen on :1965 listen tcp :1965: bind: address already in use
certmagic: could not dial :1965 dial tcp :1965: connect: connection refused
[WARNING] OS reports a contradiction: listen tcp :1965: bind: address already in use - but we cannot connect to it, with this error: dial tcp :1965: connect: connection refused; continuing anyway ๐Ÿคž

I think the error message could be changed to something like:

%v, be sure to set certmagic.DefaultACME.ListenHost to the IP you are listening on (ONLY the IP, not port)
certmagic assumes the conflicting listener is correctly configured and will continue
See #250 for more information

mholt commented

Thank you! Will look into it as soon as the weekend is over and we get over the sickness in the house ๐Ÿ˜ท

mholt commented

Ok, finally had a chance to run this. Sorry for the delay.

I think this makes sense, now that I see it for myself and have tinkered with it a bit.

Ideally, I'd like to solve the problem and know how to connect to that port. Any ideas?

But a better error message is definitely a good start.