log: console setup in a sep go routine

Author: ignoramous

intra/log/log.go

@@ -84,6 +84,10 @@ func SetConsoleLevel(level LogLevel) {
 	Glogger.SetConsoleLevel(level)
 }
 
+func ConsoleReady(ctx context.Context) {
+	Glogger.ConsoleReady(ctx)
+}
+
 // SetConsole sets external console to redirect log output to.
 func SetConsole(consoleCtx context.Context, c Console) {
 	Glogger.SetConsole(c)

intra/log/logger.go

@@ -49,6 +49,7 @@ type Logger interface {
 	SetLevel(level LogLevel)
 	SetConsoleLevel(level LogLevel)
 	SetConsole(c Console)
+	ConsoleReady(ctx context.Context)
 	Usr(msg string)
 	Printf(msg string, args ...any)
 	VeryVerbosef(at int, msg string, args ...any)
@@ -254,7 +255,6 @@ func defaultLogger() *simpleLogger {
 		o: golog.New(os.Stdout, "", defaultFlags),
 		q: newRing[string](context.TODO(), qSize),
 	}
-	go l.consoleDispatcher()
 	return l
 }
 
@@ -291,6 +291,12 @@ func (l *simpleLogger) SetConsole(c Console) {
 	l.c.set(c) // c may point to nil impl
 }
 
+func (l *simpleLogger) ConsoleReady(ctx context.Context) {
+	go l.consoleDispatcher(ctx)
+	// TODO: close l.msgC when ctx is done
+	// TODO: wireup ctx to l.q
+}
+
 func (l *simpleLogger) clearStCounts() {
 	l.stmu.Lock()
 	defer l.stmu.Unlock()
@@ -320,8 +326,13 @@ func (l *simpleLogger) incrStCount(id string) (c uint32) {
 // consoleDispatcher sends msgs from l.msgC to external log console.
 // It may drop logs on high load (50% for conNorm, 80% for conErr).
 // Must be called once from a goroutine.
-func (l *simpleLogger) consoleDispatcher() {
+func (l *simpleLogger) consoleDispatcher(ctx context.Context) {
 	for m := range l.cmsgC {
+		select {
+		case <-ctx.Done():
+			return
+		default:
+		}
 		if m == nil || len(m.m) <= 0 { // no msg
 			continue
 		}

intra/log/ring.go

@@ -29,15 +29,10 @@ func newRing[T any](ctx context.Context, capacity int) *ring[T] {
 		inC: make(chan T, capacity/2),
 	}
 	go r.process()
+	context.AfterFunc(ctx, func() { close(r.inC) })
 	return r
 }
 
-func (r *ring[T]) closeWaiter() {
-	defer close(r.inC)
-
-	<-r.ctx.Done()
-}
-
 // Push adds an element to the ring buffer
 func (r *ring[T]) Push(v T) (ok bool) {
 	select {
@@ -56,8 +51,6 @@ func (r *ring[T]) Push(v T) (ok bool) {
 // process reads from the input channel and adds elements to the ring buffer.
 // Must be run in a goroutine.
 func (r *ring[T]) process() {
-	go r.closeWaiter()
-
 	for v := range r.inC {
 		r.Lock()
 		r.b[r.head] = v

intra/tunnel.go

@@ -186,24 +186,34 @@ func NewTunnel2(fd, linkmtu, tunmtu int, ifaddrs, fakedns string, dtr DefaultDNS
 
 	const dualstack = settings.IP46
 
-	logfd := false
-	if r, c, err := log.NewFilebased(); err == nil {
-		closeall := func() {
-			core.Close(c)
-			core.Close(r)
+	logch := make(chan bool, 1)
+	crashch := make(chan bool, 1)
+	go func() {
+		logfd := false
+		if r, c, err := log.NewFilebased(); err == nil {
+			closeall := func() {
+				core.Close(c)
+				core.Close(r)
+			}
+			if logfd = bdg.LogFD(int(r.Fd())); logfd {
+				log.SetConsole(ctx, c)
+				context.AfterFunc(ctx, closeall)
+			} else {
+				closeall()
+			}
 		}
-		if logfd = bdg.LogFD(int(r.Fd())); logfd {
-			log.SetConsole(ctx, c)
-			context.AfterFunc(ctx, closeall)
-		} else {
-			closeall()
+		if !logfd {
+			log.SetConsole(ctx, &clogAdapter{bdg})
 		}
-	}
-	if !logfd {
-		log.SetConsole(ctx, &clogAdapter{bdg})
-	}
+		log.D("tun: <<< new >>>; log out ok; fd? %t", logfd)
+		logch <- logfd
+	}()
 
-	crashfd := pipeCrashOutput(bdg)
+	go func() {
+		crashfd := pipeCrashOutput(bdg)
+		crashch <- crashfd
+		log.D("tun: <<< new >>>; crash out ok; fd? %t", crashfd)
+	}()
 
 	natpt := x64.NewNatPt2(ctx)
 	proxies := ipn.NewProxifier(ctx, dualstack, linkmtu, bdg, bdg)
@@ -214,12 +224,21 @@ func NewTunnel2(fd, linkmtu, tunmtu int, ifaddrs, fakedns string, dtr DefaultDNS
 			proxies == nil, services == nil)
 	}
 
+	// kickstart may call into ProxyFor which has a multi-second wait time
+	// when proxies are not found
 	if err := dtr.kickstart(proxies); err != nil {
 		log.W("tun: <<< new >>>; kickstart err(%v)", err)
 		return nil, err
 	}
 
-	log.D("tun: <<< new >>>; proxies, svcs, bootstrap: ok; fds (log? %t / crash? %t)", logfd, crashfd)
+	log.D("tun: <<< new >>>; default dns: ok")
+
+	logfd := <-logch
+	crashfd := <-crashch
+
+	log.ConsoleReady(ctx)
+
+	log.D("tun: <<< new >>>; logger, proxies, svcs, bootstrap: ok; fds (log? %t / crash? %t)", logfd, crashfd)
 
 	resolver := dnsx.NewResolver(ctx, fakedns, dtr, bdg, natpt)
 	resolver.Add(newGoosTransport(ctx, proxies))            // os-resolver; fixed