diff --git a/cmd/ctrld/dns_proxy.go b/cmd/ctrld/dns_proxy.go index 0f3d085..8ece9c1 100644 --- a/cmd/ctrld/dns_proxy.go +++ b/cmd/ctrld/dns_proxy.go @@ -37,7 +37,7 @@ func (p *prog) serveUDP(listenerNum string) error { fmtSrcToDest := fmtRemoteToLocal(listenerNum, w.RemoteAddr().String(), w.LocalAddr().String()) t := time.Now() ctx := context.WithValue(context.Background(), ctrld.ReqIdCtxKey{}, reqId) - ctrld.Log(ctx, proxyLog.Debug(), "%s received query: %s", fmtSrcToDest, domain) + ctrld.Log(ctx, mainLog.Debug(), "%s received query: %s", fmtSrcToDest, domain) upstreams, matched := p.upstreamFor(ctx, listenerNum, listenerConfig, w.RemoteAddr(), domain) var answer *dns.Msg if !matched && listenerConfig.Restricted { @@ -47,7 +47,7 @@ func (p *prog) serveUDP(listenerNum string) error { } else { answer = p.proxy(ctx, upstreams, failoverRcodes, m) rtt := time.Since(t) - ctrld.Log(ctx, proxyLog.Debug(), "received response of %d bytes in %s", answer.Len(), rtt) + ctrld.Log(ctx, mainLog.Debug(), "received response of %d bytes in %s", answer.Len(), rtt) } if err := w.WriteMsg(answer); err != nil { ctrld.Log(ctx, mainLog.Error().Err(err), "serveUDP: failed to send DNS response to client") @@ -84,10 +84,10 @@ func (p *prog) upstreamFor(ctx context.Context, defaultUpstreamNum string, lc *c defer func() { if !matched && lc.Restricted { - ctrld.Log(ctx, proxyLog.Info(), "query refused, %s does not match any network policy", addr.String()) + ctrld.Log(ctx, mainLog.Info(), "query refused, %s does not match any network policy", addr.String()) return } - ctrld.Log(ctx, proxyLog.Info(), "%s, %s, %s -> %v", matchedPolicy, matchedNetwork, matchedRule, upstreams) + ctrld.Log(ctx, mainLog.Info(), "%s, %s, %s -> %v", matchedPolicy, matchedNetwork, matchedRule, upstreams) }() if lc.Policy == nil { @@ -160,7 +160,7 @@ func (p *prog) proxy(ctx context.Context, upstreams []string, failoverRcodes []i answer.SetRcode(msg, answer.Rcode) now := time.Now() if cachedValue.Expire.After(now) { - ctrld.Log(ctx, proxyLog.Debug(), "hit cached response") + ctrld.Log(ctx, mainLog.Debug(), "hit cached response") setCachedAnswerTTL(answer, now, cachedValue.Expire) return answer } @@ -168,10 +168,10 @@ func (p *prog) proxy(ctx context.Context, upstreams []string, failoverRcodes []i } } resolve := func(n int, upstreamConfig *ctrld.UpstreamConfig, msg *dns.Msg) *dns.Msg { - ctrld.Log(ctx, proxyLog.Debug(), "sending query to %s: %s", upstreams[n], upstreamConfig.Name) + ctrld.Log(ctx, mainLog.Debug(), "sending query to %s: %s", upstreams[n], upstreamConfig.Name) dnsResolver, err := ctrld.NewResolver(upstreamConfig) if err != nil { - ctrld.Log(ctx, proxyLog.Error().Err(err), "failed to create resolver") + ctrld.Log(ctx, mainLog.Error().Err(err), "failed to create resolver") return nil } resolveCtx, cancel := context.WithCancel(ctx) @@ -183,7 +183,7 @@ func (p *prog) proxy(ctx context.Context, upstreams []string, failoverRcodes []i } answer, err := dnsResolver.Resolve(resolveCtx, msg) if err != nil { - ctrld.Log(ctx, proxyLog.Error().Err(err), "failed to resolve query") + ctrld.Log(ctx, mainLog.Error().Err(err), "failed to resolve query") return nil } return answer @@ -192,7 +192,7 @@ func (p *prog) proxy(ctx context.Context, upstreams []string, failoverRcodes []i answer := resolve(n, upstreamConfig, msg) if answer == nil { if serveStaleCache && staleAnswer != nil { - ctrld.Log(ctx, proxyLog.Debug(), "serving stale cached response") + ctrld.Log(ctx, mainLog.Debug(), "serving stale cached response") now := time.Now() setCachedAnswerTTL(staleAnswer, now, now.Add(staleTTL)) return staleAnswer @@ -200,7 +200,7 @@ func (p *prog) proxy(ctx context.Context, upstreams []string, failoverRcodes []i continue } if answer.Rcode != dns.RcodeSuccess && len(upstreamConfigs) > 1 && containRcode(failoverRcodes, answer.Rcode) { - ctrld.Log(ctx, proxyLog.Debug(), "failover rcode matched, process to next upstream") + ctrld.Log(ctx, mainLog.Debug(), "failover rcode matched, process to next upstream") continue } if p.cache != nil { @@ -212,11 +212,11 @@ func (p *prog) proxy(ctx context.Context, upstreams []string, failoverRcodes []i } setCachedAnswerTTL(answer, now, expired) p.cache.Add(dnscache.NewKey(msg, upstreams[n]), dnscache.NewValue(answer, expired)) - ctrld.Log(ctx, proxyLog.Debug(), "add cached response") + ctrld.Log(ctx, mainLog.Debug(), "add cached response") } return answer } - ctrld.Log(ctx, proxyLog.Error(), "all upstreams failed") + ctrld.Log(ctx, mainLog.Error(), "all upstreams failed") answer := new(dns.Msg) answer.SetRcode(msg, dns.RcodeServerFailure) return answer diff --git a/cmd/ctrld/main.go b/cmd/ctrld/main.go index 5c55123..033fd2e 100644 --- a/cmd/ctrld/main.go +++ b/cmd/ctrld/main.go @@ -31,7 +31,6 @@ var ( rootLogger = zerolog.New(io.Discard) mainLog = rootLogger - proxyLog = rootLogger cdUID string iface string @@ -59,7 +58,6 @@ func normalizeLogFilePath(logFilePath string) string { func initLogging() { writers := []io.Writer{io.Discard} - isLog := cfg.Service.LogLevel != "" if logFilePath := normalizeLogFilePath(cfg.Service.LogPath); logFilePath != "" { // Create parent directory if necessary. if err := os.MkdirAll(filepath.Dir(logFilePath), 0750); err != nil { @@ -71,7 +69,6 @@ func initLogging() { fmt.Fprintf(os.Stderr, "failed to create log file: %v", err) os.Exit(1) } - isLog = true writers = append(writers, logFile) } zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMs @@ -81,11 +78,8 @@ func initLogging() { writers = append(writers, consoleWriter) multi := zerolog.MultiLevelWriter(writers...) mainLog = mainLog.Output(multi).With().Timestamp().Logger() - if verbose > 0 || isLog { - proxyLog = proxyLog.Output(multi).With().Timestamp().Logger() - // TODO: find a better way. - ctrld.ProxyLog = proxyLog - } + // TODO: find a better way. + ctrld.ProxyLog = mainLog zerolog.SetGlobalLevel(zerolog.InfoLevel) logLevel := cfg.Service.LogLevel diff --git a/cmd/ctrld/prog.go b/cmd/ctrld/prog.go index d99449c..2046be4 100644 --- a/cmd/ctrld/prog.go +++ b/cmd/ctrld/prog.go @@ -52,7 +52,7 @@ func (p *prog) run() { for _, cidr := range nc.Cidrs { _, ipNet, err := net.ParseCIDR(cidr) if err != nil { - proxyLog.Error().Err(err).Str("network", nc.Name).Str("cidr", cidr).Msg("invalid cidr") + mainLog.Error().Err(err).Str("network", nc.Name).Str("cidr", cidr).Msg("invalid cidr") continue } nc.IPNets = append(nc.IPNets, ipNet) @@ -73,11 +73,11 @@ func (p *prog) run() { m.RecursionDesired = true r, _, err := c.Exchange(m, net.JoinHostPort(bootstrapDNS, "53")) if err != nil { - proxyLog.Error().Err(err).Msgf("could not resolve domain %s for upstream.%s", uc.Domain, n) + mainLog.Error().Err(err).Msgf("could not resolve domain %s for upstream.%s", uc.Domain, n) continue } if r.Rcode != dns.RcodeSuccess { - proxyLog.Error().Msgf("could not resolve domain return code: %d, upstream.%s", r.Rcode, n) + mainLog.Error().Msgf("could not resolve domain return code: %d, upstream.%s", r.Rcode, n) continue } if len(r.Answer) == 0 { @@ -110,14 +110,14 @@ func (p *prog) run() { listenerConfig := p.cfg.Listener[listenerNum] upstreamConfig := p.cfg.Upstream[listenerNum] if upstreamConfig == nil { - proxyLog.Error().Msgf("missing upstream config for: [listener.%s]", listenerNum) + mainLog.Error().Msgf("missing upstream config for: [listener.%s]", listenerNum) return } addr := net.JoinHostPort(listenerConfig.IP, strconv.Itoa(listenerConfig.Port)) mainLog.Info().Msgf("Starting DNS server on listener.%s: %s", listenerNum, addr) err := p.serveUDP(listenerNum) if err != nil && !defaultConfigWritten { - proxyLog.Fatal().Err(err).Msgf("Unable to start dns proxy on listener.%s", listenerNum) + mainLog.Fatal().Err(err).Msgf("Unable to start dns proxy on listener.%s", listenerNum) return } if err == nil { @@ -126,16 +126,16 @@ func (p *prog) run() { if opErr, ok := err.(*net.OpError); ok { if sErr, ok := opErr.Err.(*os.SyscallError); ok && errors.Is(opErr.Err, syscall.EADDRINUSE) || errors.Is(sErr.Err, errWindowsAddrInUse) { - proxyLog.Warn().Msgf("Address %s already in used, pick a random one", addr) + mainLog.Warn().Msgf("Address %s already in used, pick a random one", addr) pc, err := net.ListenPacket("udp", net.JoinHostPort(listenerConfig.IP, "0")) if err != nil { - proxyLog.Fatal().Err(err).Msg("failed to listen packet") + mainLog.Fatal().Err(err).Msg("failed to listen packet") return } _, portStr, _ := net.SplitHostPort(pc.LocalAddr().String()) port, err := strconv.Atoi(portStr) if err != nil { - proxyLog.Fatal().Err(err).Msg("malformed port") + mainLog.Fatal().Err(err).Msg("malformed port") return } listenerConfig.Port = port @@ -146,7 +146,7 @@ func (p *prog) run() { }, }) if err := writeConfigFile(); err != nil { - proxyLog.Fatal().Err(err).Msg("failed to write config file") + mainLog.Fatal().Err(err).Msg("failed to write config file") } else { mainLog.Info().Msg("writing config file to: " + defaultConfigFile) } @@ -154,16 +154,16 @@ func (p *prog) run() { // There can be a race between closing the listener and start our own UDP server, but it's // rare, and we only do this once, so let conservative here. if err := pc.Close(); err != nil { - proxyLog.Fatal().Err(err).Msg("failed to close packet conn") + mainLog.Fatal().Err(err).Msg("failed to close packet conn") return } if err := p.serveUDP(listenerNum); err != nil { - proxyLog.Fatal().Err(err).Msgf("Unable to start dns proxy on listener.%s", listenerNum) + mainLog.Fatal().Err(err).Msgf("Unable to start dns proxy on listener.%s", listenerNum) return } } } - proxyLog.Fatal().Err(err).Msgf("Unable to start dns proxy on listener.%s", listenerNum) + mainLog.Fatal().Err(err).Msgf("Unable to start dns proxy on listener.%s", listenerNum) }(listenerNum) }