Implement net.Listener hand-over during config reload

Log library refactored a little to make it easier to enable debug logging.

Author: foxcpp

framework/log/log.go

@@ -42,6 +42,8 @@ import (
 // No serialization is provided by Logger, its log.Output responsibility to
 // ensure goroutine-safety if necessary.
 type Logger struct {
+	Parent *Logger
+
 	Out   Output
 	Name  string
 	Debug bool
@@ -51,30 +53,37 @@ type Logger struct {
 	Fields map[string]interface{}
 }
 
-func (l Logger) Zap() *zap.Logger {
+func (l *Logger) Zap() *zap.Logger {
 	// TODO: Migrate to using zap natively.
 	return zap.New(zapLogger{L: l})
 }
 
-func (l Logger) Debugf(format string, val ...interface{}) {
-	if !l.Debug {
+func (l *Logger) IsDebug() bool {
+	if l.Parent == nil {
+		return l.Debug
+	}
+	return l.Debug || l.Parent.IsDebug()
+}
+
+func (l *Logger) Debugf(format string, val ...interface{}) {
+	if !l.IsDebug() {
 		return
 	}
 	l.log(true, l.formatMsg(fmt.Sprintf(format, val...), nil))
 }
 
-func (l Logger) Debugln(val ...interface{}) {
-	if !l.Debug {
+func (l *Logger) Debugln(val ...interface{}) {
+	if !l.IsDebug() {
 		return
 	}
 	l.log(true, l.formatMsg(strings.TrimRight(fmt.Sprintln(val...), "\n"), nil))
 }
 
-func (l Logger) Printf(format string, val ...interface{}) {
+func (l *Logger) Printf(format string, val ...interface{}) {
 	l.log(false, l.formatMsg(fmt.Sprintf(format, val...), nil))
 }
 
-func (l Logger) Println(val ...interface{}) {
+func (l *Logger) Println(val ...interface{}) {
 	l.log(false, l.formatMsg(strings.TrimRight(fmt.Sprintln(val...), "\n"), nil))
 }
 
@@ -87,13 +96,13 @@ func (l Logger) Println(val ...interface{}) {
 // followed by corresponding values.  That is, for example, []interface{"key",
 // "value", "key2", "value2"}.
 //
-// If value in fields implements LogFormatter, it will be represented by the
+// If value in fields implements Formatter, it will be represented by the
 // string returned by FormatLog method. Same goes for fmt.Stringer and error
 // interfaces.
 //
 // Additionally, time.Time is written as a string in ISO 8601 format.
 // time.Duration follows fmt.Stringer rule above.
-func (l Logger) Msg(msg string, fields ...interface{}) {
+func (l *Logger) Msg(msg string, fields ...interface{}) {
 	m := make(map[string]interface{}, len(fields)/2)
 	fieldsToMap(fields, m)
 	l.log(false, l.formatMsg(msg, m))
@@ -112,7 +121,7 @@ func (l Logger) Msg(msg string, fields ...interface{}) {
 // In the context of Error method, "msg" typically indicates the top-level
 // context in which the error is *handled*. For example, if error leads to
 // rejection of SMTP DATA command, msg will probably be "DATA error".
-func (l Logger) Error(msg string, err error, fields ...interface{}) {
+func (l *Logger) Error(msg string, err error, fields ...interface{}) {
 	if err == nil {
 		return
 	}
@@ -133,8 +142,8 @@ func (l Logger) Error(msg string, err error, fields ...interface{}) {
 	l.log(false, l.formatMsg(msg, allFields))
 }
 
-func (l Logger) DebugMsg(kind string, fields ...interface{}) {
-	if !l.Debug {
+func (l *Logger) DebugMsg(kind string, fields ...interface{}) {
+	if !l.IsDebug() {
 		return
 	}
 	m := make(map[string]interface{}, len(fields)/2)
@@ -162,7 +171,7 @@ func fieldsToMap(fields []interface{}, out map[string]interface{}) {
 	}
 }
 
-func (l Logger) formatMsg(msg string, fields map[string]interface{}) string {
+func (l *Logger) formatMsg(msg string, fields map[string]interface{}) string {
 	formatted := strings.Builder{}
 
 	formatted.WriteString(msg)
@@ -184,30 +193,31 @@ func (l Logger) formatMsg(msg string, fields map[string]interface{}) string {
 	return formatted.String()
 }
 
-type LogFormatter interface {
+type Formatter interface {
 	FormatLog() string
 }
 
 // Write implements io.Writer, all bytes sent
 // to it will be written as a separate log messages.
 // No line-buffering is done.
-func (l Logger) Write(s []byte) (int, error) {
+func (l *Logger) Write(s []byte) (int, error) {
+	if !l.IsDebug() {
+		return len(s), nil
+	}
 	l.log(false, strings.TrimRight(string(s), "\n"))
 	return len(s), nil
 }
 
 // DebugWriter returns a writer that will act like Logger.Write
 // but will use debug flag on messages. If Logger.Debug is false,
 // Write method of returned object will be no-op.
-func (l Logger) DebugWriter() io.Writer {
-	if !l.Debug {
-		return io.Discard
-	}
-	l.Debug = true
-	return &l
+func (l *Logger) DebugWriter() io.Writer {
+	l2 := l.Sublogger("")
+	l2.Debug = true
+	return l2
 }
 
-func (l Logger) log(debug bool, s string) {
+func (l *Logger) log(debug bool, s string) {
 	if l.Name != "" {
 		s = l.Name + ": " + s
 	}
@@ -224,14 +234,15 @@ func (l Logger) log(debug bool, s string) {
 	// Logging is disabled - do nothing.
 }
 
-func (l Logger) Sublogger(name string) Logger {
-	if l.Name != "" {
+func (l *Logger) Sublogger(name string) *Logger {
+	if l.Name != "" && name != "" {
 		name = l.Name + "/" + name
 	}
-	return Logger{
-		Out:   l.Out,
-		Name:  name,
-		Debug: l.Debug,
+	return &Logger{
+		Parent: l,
+		Out:    l.Out,
+		Name:   name,
+		Debug:  l.Debug,
 	}
 }
 

framework/log/orderedjson.go

@@ -58,7 +58,7 @@ func marshalOrderedJSON(output *strings.Builder, m map[string]interface{}) error
 			val = casted.Format("2006-01-02T15:04:05.000")
 		case time.Duration:
 			val = casted.String()
-		case LogFormatter:
+		case Formatter:
 			val = casted.FormatLog()
 		case fmt.Stringer:
 			val = casted.String()

framework/log/zap.go

@@ -7,7 +7,7 @@ import (
 // TODO: Migrate to using actual zapcore to improve logging performance
 
 type zapLogger struct {
-	L Logger
+	L *Logger
 }
 
 func (l zapLogger) Enabled(level zapcore.Level) bool {

framework/module/lifetime.go

@@ -38,7 +38,7 @@ type ReloadModule interface {
 }
 
 type LifetimeTracker struct {
-	logger    log.Logger
+	logger    *log.Logger
 	instances []*struct {
 		mod     LifetimeModule
 		started bool
@@ -114,7 +114,7 @@ func (lt *LifetimeTracker) StopAll() error {
 	return nil
 }
 
-func NewLifetime(log log.Logger) *LifetimeTracker {
+func NewLifetime(log *log.Logger) *LifetimeTracker {
 	return &LifetimeTracker{
 		logger: log,
 	}

framework/module/registry.go

@@ -35,14 +35,14 @@ type registryEntry struct {
 }
 
 type Registry struct {
-	logger      log.Logger
+	logger      *log.Logger
 	instances   map[string]registryEntry
 	initialized map[string]struct{}
 	started     map[string]struct{}
 	aliases     map[string]string
 }
 
-func NewRegistry(log log.Logger) *Registry {
+func NewRegistry(log *log.Logger) *Registry {
 	return &Registry{
 		logger:      log,
 		instances:   make(map[string]registryEntry),

framework/resource/netresource/dup.go

@@ -0,0 +1,27 @@
+package netresource
+
+import "net"
+
+func dupTCPListener(l *net.TCPListener) (*net.TCPListener, error) {
+	f, err := l.File()
+	if err != nil {
+		return nil, err
+	}
+	l2, err := net.FileListener(f)
+	if err != nil {
+		return nil, err
+	}
+	return l2.(*net.TCPListener), nil
+}
+
+func dupUnixListener(l *net.UnixListener) (*net.UnixListener, error) {
+	f, err := l.File()
+	if err != nil {
+		return nil, err
+	}
+	l2, err := net.FileListener(f)
+	if err != nil {
+		return nil, err
+	}
+	return l2.(*net.UnixListener), nil
+}

framework/resource/netresource/fd.go

@@ -0,0 +1,47 @@
+package netresource
+
+import (
+	"errors"
+	"fmt"
+	"net"
+	"os"
+	"strconv"
+	"strings"
+)
+
+func ListenFD(fd uint) (net.Listener, error) {
+	file := os.NewFile(uintptr(fd), strconv.FormatUint(uint64(fd), 10))
+	defer file.Close()
+	return net.FileListener(file)
+}
+
+func ListenFDName(name string) (net.Listener, error) {
+	listenPDStr := os.Getenv("LISTEN_PID")
+	if listenPDStr == "" {
+		return nil, errors.New("$LISTEN_PID is not set")
+	}
+	listenPid, err := strconv.Atoi(listenPDStr)
+	if err != nil {
+		return nil, errors.New("$LISTEN_PID is not integer")
+	}
+	if listenPid != os.Getpid() {
+		return nil, fmt.Errorf("$LISTEN_PID (%d) is not our PID (%d)", listenPid, os.Getpid())
+	}
+
+	names := strings.Split(os.Getenv("LISTEN_FDNAMES"), ":")
+	fd := uintptr(0)
+	for i, fdName := range names {
+		if fdName == name {
+			fd = uintptr(3 + i)
+			break
+		}
+	}
+
+	if fd == 0 {
+		return nil, fmt.Errorf("name %s not found in $LISTEN_FDNAMES", name)
+	}
+
+	file := os.NewFile(3+fd, name)
+	defer file.Close()
+	return net.FileListener(file)
+}

framework/resource/netresource/listen.go

@@ -0,0 +1,38 @@
+package netresource
+
+import (
+	"fmt"
+	"net"
+	"strconv"
+
+	"github.com/foxcpp/maddy/framework/log"
+)
+
+var (
+	tracker = NewListenerTracker(log.DefaultLogger.Sublogger("netresource"))
+)
+
+func CloseUnusedListeners() error {
+	return tracker.Close()
+}
+
+func ResetListenersUsage() {
+	tracker.ResetUsage()
+}
+
+func Listen(network, addr string) (net.Listener, error) {
+	switch network {
+	case "fd":
+		fd, err := strconv.ParseUint(addr, 10, strconv.IntSize)
+		if err != nil {
+			return nil, fmt.Errorf("invalid FD number: %v", addr)
+		}
+		return ListenFD(uint(fd))
+	case "fdname":
+		return ListenFDName(addr)
+	case "tcp", "tcp4", "tcp6", "unix":
+		return tracker.Get(network, addr)
+	default:
+		return nil, fmt.Errorf("unsupported network: %v", network)
+	}
+}