CalvinBackup/ctrld
1
0
Fork 0
mirror of https://github.com/Control-D-Inc/ctrld.git synced 2026-02-03 22:18:39 +00:00
Code Issues Packages Projects Releases Wiki Activity

cmd/ctrld: merge proxy log to main log

Browse Source 
There's no reason to separate those two loggers anymore, and making them
separated may lead to inconsistent logging behavior.

Updates #54
This commit is contained in:
Cuong Manh Le
2023-02-15 09:27:11 +07:00
committed by Cuong Manh Le
parent 71b1b324db
commit d9b699501d
3 changed files with 26 additions and 32 deletions
Download Patch File Download Diff File Expand all files Collapse all files

24
cmd/ctrld/dns_proxy.go
View File

@@ -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

10
cmd/ctrld/main.go
View File

@@ -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

24
cmd/ctrld/prog.go
View File

@@ -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)
}