diff --git a/autotls/autotls.go b/autotls/autotls.go index d9f8c2a..6009f35 100644 --- a/autotls/autotls.go +++ b/autotls/autotls.go @@ -240,7 +240,11 @@ func (m *Manager) SetAllowedHostnames(log mlog.Log, resolver dns.Resolver, hostn } for _, ip := range ips { if _, ok := publicIPstrs[ip.String()]; !ok { - log.Error("warning: acme tls cert validation for host is likely to fail because not all its ips are being listened on", slog.Any("hostname", h), slog.Any("listenedips", publicIPs), slog.Any("hostips", ips), slog.Any("missingip", ip)) + log.Error("warning: acme tls cert validation for host is likely to fail because not all its ips are being listened on", + slog.Any("hostname", h), + slog.Any("listenedips", publicIPs), + slog.Any("hostips", ips), + slog.Any("missingip", ip)) } } } diff --git a/backup.go b/backup.go index 462ff6b..6022399 100644 --- a/backup.go +++ b/backup.go @@ -166,7 +166,10 @@ func backupctl(ctx context.Context, ctl *ctl) { return nil }) if err != nil { - xerrx("copying directory (not backed up properly)", err, slog.String("srcdir", srcdir), slog.String("dstdir", dstdir), slog.Duration("duration", time.Since(tmDir))) + xerrx("copying directory (not backed up properly)", err, + slog.String("srcdir", srcdir), + slog.String("dstdir", dstdir), + slog.Duration("duration", time.Since(tmDir))) return } xvlog("backed up directory", slog.String("dir", dir), slog.Duration("duration", time.Since(tmDir))) @@ -341,7 +344,10 @@ func backupctl(ctx context.Context, ctl *ctl) { if err != nil { xerrx("processing queue messages (not backed up properly)", err, slog.Duration("duration", time.Since(tmMsgs))) } else { - xvlog("queue message files linked/copied", slog.Int("linked", nlinked), slog.Int("copied", ncopied), slog.Duration("duration", time.Since(tmMsgs))) + xvlog("queue message files linked/copied", + slog.Int("linked", nlinked), + slog.Int("copied", ncopied), + slog.Duration("duration", time.Since(tmMsgs))) } // Read through all files in queue directory and warn about anything we haven't handled yet. @@ -445,7 +451,10 @@ func backupctl(ctx context.Context, ctl *ctl) { if err != nil { xerrx("processing account messages (not backed up properly)", err, slog.Duration("duration", time.Since(tmMsgs))) } else { - xvlog("account message files linked/copied", slog.Int("linked", nlinked), slog.Int("copied", ncopied), slog.Duration("duration", time.Since(tmMsgs))) + xvlog("account message files linked/copied", + slog.Int("linked", nlinked), + slog.Int("copied", ncopied), + slog.Duration("duration", time.Since(tmMsgs))) } // Read through all files in account directory and warn about anything we haven't handled yet. diff --git a/dkim/dkim.go b/dkim/dkim.go index 353a9ea..931fc2d 100644 --- a/dkim/dkim.go +++ b/dkim/dkim.go @@ -127,7 +127,11 @@ func Sign(ctx context.Context, elog *slog.Logger, localpart smtp.Localpart, doma log := mlog.New("dkim", elog) start := timeNow() defer func() { - log.Debugx("dkim sign result", rerr, slog.Any("localpart", localpart), slog.Any("domain", domain), slog.Bool("smtputf8", smtputf8), slog.Duration("duration", time.Since(start))) + log.Debugx("dkim sign result", rerr, + slog.Any("localpart", localpart), + slog.Any("domain", domain), + slog.Bool("smtputf8", smtputf8), + slog.Duration("duration", time.Since(start))) }() hdrs, bodyOffset, err := parseHeaders(bufio.NewReader(&moxio.AtReader{R: msg})) @@ -274,7 +278,12 @@ func Lookup(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, selec log := mlog.New("dkim", elog) start := timeNow() defer func() { - log.Debugx("dkim lookup result", rerr, slog.Any("selector", selector), slog.Any("domain", domain), slog.Any("status", rstatus), slog.Any("record", rrecord), slog.Duration("duration", time.Since(start))) + log.Debugx("dkim lookup result", rerr, + slog.Any("selector", selector), + slog.Any("domain", domain), + slog.Any("status", rstatus), + slog.Any("record", rrecord), + slog.Duration("duration", time.Since(start))) }() name := selector.ASCII + "._domainkey." + domain.ASCII + "." @@ -356,7 +365,12 @@ func Verify(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, smtpu log.Debugx("dkim verify result", rerr, slog.Bool("smtputf8", smtputf8), slog.Duration("duration", time.Since(start))) } for _, result := range results { - log.Debugx("dkim verify result", result.Err, slog.Bool("smtputf8", smtputf8), slog.Any("status", result.Status), slog.Any("sig", result.Sig), slog.Any("record", result.Record), slog.Duration("duration", time.Since(start))) + log.Debugx("dkim verify result", result.Err, + slog.Bool("smtputf8", smtputf8), + slog.Any("status", result.Status), + slog.Any("sig", result.Sig), + slog.Any("record", result.Record), + slog.Duration("duration", time.Since(start))) } }() diff --git a/dmarc/dmarc.go b/dmarc/dmarc.go index dda9448..b688815 100644 --- a/dmarc/dmarc.go +++ b/dmarc/dmarc.go @@ -103,7 +103,12 @@ func Lookup(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, from log := mlog.New("dmarc", elog) start := time.Now() defer func() { - log.Debugx("dmarc lookup result", rerr, slog.Any("fromdomain", from), slog.Any("status", status), slog.Any("domain", domain), slog.Any("record", record), slog.Duration("duration", time.Since(start))) + log.Debugx("dmarc lookup result", rerr, + slog.Any("fromdomain", from), + slog.Any("status", status), + slog.Any("domain", domain), + slog.Any("record", record), + slog.Duration("duration", time.Since(start))) }() // ../rfc/7489:859 ../rfc/7489:1370 @@ -206,7 +211,12 @@ func LookupExternalReportsAccepted(ctx context.Context, elog *slog.Logger, resol log := mlog.New("dmarc", elog) start := time.Now() defer func() { - log.Debugx("dmarc externalreports result", rerr, slog.Bool("accepts", accepts), slog.Any("dmarcdomain", dmarcDomain), slog.Any("extdestdomain", extDestDomain), slog.Any("records", records), slog.Duration("duration", time.Since(start))) + log.Debugx("dmarc externalreports result", rerr, + slog.Bool("accepts", accepts), + slog.Any("dmarcdomain", dmarcDomain), + slog.Any("extdestdomain", extDestDomain), + slog.Any("records", records), + slog.Duration("duration", time.Since(start))) }() status, records, txts, authentic, rerr = lookupReportsRecord(ctx, resolver, dmarcDomain, extDestDomain) @@ -239,7 +249,14 @@ func Verify(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, from reject = "yes" } metricDMARCVerify.WithLabelValues(string(result.Status), reject, use).Observe(float64(time.Since(start)) / float64(time.Second)) - log.Debugx("dmarc verify result", result.Err, slog.Any("fromdomain", from), slog.Any("dkimresults", dkimResults), slog.Any("spfresult", spfResult), slog.Any("status", result.Status), slog.Bool("reject", result.Reject), slog.Bool("use", useResult), slog.Duration("duration", time.Since(start))) + log.Debugx("dmarc verify result", result.Err, + slog.Any("fromdomain", from), + slog.Any("dkimresults", dkimResults), + slog.Any("spfresult", spfResult), + slog.Any("status", result.Status), + slog.Bool("reject", result.Reject), + slog.Bool("use", useResult), + slog.Duration("duration", time.Since(start))) }() status, recordDomain, record, _, authentic, err := Lookup(ctx, log.Logger, resolver, from) diff --git a/dnsbl/dnsbl.go b/dnsbl/dnsbl.go index afb66f8..8114f70 100644 --- a/dnsbl/dnsbl.go +++ b/dnsbl/dnsbl.go @@ -50,7 +50,12 @@ func Lookup(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, zone start := time.Now() defer func() { metricLookup.WithLabelValues(zone.Name(), string(rstatus)).Observe(float64(time.Since(start)) / float64(time.Second)) - log.Debugx("dnsbl lookup result", rerr, slog.Any("zone", zone), slog.Any("ip", ip), slog.Any("status", rstatus), slog.String("explanation", rexplanation), slog.Duration("duration", time.Since(start))) + log.Debugx("dnsbl lookup result", rerr, + slog.Any("zone", zone), + slog.Any("ip", ip), + slog.Any("status", rstatus), + slog.String("explanation", rexplanation), + slog.Duration("duration", time.Since(start))) }() b := &strings.Builder{} diff --git a/http/gzcache.go b/http/gzcache.go index e910cb6..f3208c8 100644 --- a/http/gzcache.go +++ b/http/gzcache.go @@ -115,7 +115,10 @@ func loadStaticGzipCache(dir string, maxSize int64) { if err != nil { pkglog.Infox("removing unusable/unrecognized file in static gzip cache dir", err) xerr := os.Remove(filepath.Join(dir, name)) - pkglog.Check(xerr, "removing unusable file in static gzip cache dir", slog.Any("error", err), slog.String("dir", dir), slog.String("filename", name)) + pkglog.Check(xerr, "removing unusable file in static gzip cache dir", + slog.Any("error", err), + slog.String("dir", dir), + slog.String("filename", name)) continue } staticgzcache.paths[path] = gzfile{ diff --git a/http/web.go b/http/web.go index 6b1e460..a69c11b 100644 --- a/http/web.go +++ b/http/web.go @@ -746,7 +746,10 @@ func listen1(ip string, port int, tlsConfig *tls.Config, name string, kinds []st if tlsConfig == nil { protocol = "http" if os.Getuid() == 0 { - pkglog.Print("http listener", slog.String("name", name), slog.String("kinds", strings.Join(kinds, ",")), slog.String("address", addr)) + pkglog.Print("http listener", + slog.String("name", name), + slog.String("kinds", strings.Join(kinds, ",")), + slog.String("address", addr)) } ln, err = mox.Listen(mox.Network(ip), addr) if err != nil { @@ -755,7 +758,10 @@ func listen1(ip string, port int, tlsConfig *tls.Config, name string, kinds []st } else { protocol = "https" if os.Getuid() == 0 { - pkglog.Print("https listener", slog.String("name", name), slog.String("kinds", strings.Join(kinds, ",")), slog.String("address", addr)) + pkglog.Print("https listener", + slog.String("name", name), + slog.String("kinds", strings.Join(kinds, ",")), + slog.String("address", addr)) } ln, err = mox.Listen(mox.Network(ip), addr) if err != nil { diff --git a/imapserver/server.go b/imapserver/server.go index 599b570..ac7b641 100644 --- a/imapserver/server.go +++ b/imapserver/server.go @@ -339,7 +339,10 @@ func listen1(protocol, listenerName, ip string, port int, tlsConfig *tls.Config, log := mlog.New("imapserver", nil) addr := net.JoinHostPort(ip, fmt.Sprintf("%d", port)) if os.Getuid() == 0 { - log.Print("listening for imap", slog.String("listener", listenerName), slog.String("addr", addr), slog.String("protocol", protocol)) + log.Print("listening for imap", + slog.String("listener", listenerName), + slog.String("addr", addr), + slog.String("protocol", protocol)) } network := mox.Network(ip) ln, err := mox.Listen(network, addr) @@ -664,7 +667,11 @@ func serve(listenerName string, cid int64, tlsConfig *tls.Config, nc net.Conn, x } } - c.log.Info("new connection", slog.Any("remote", c.conn.RemoteAddr()), slog.Any("local", c.conn.LocalAddr()), slog.Bool("tls", xtls), slog.String("listener", listenerName)) + c.log.Info("new connection", + slog.Any("remote", c.conn.RemoteAddr()), + slog.Any("local", c.conn.LocalAddr()), + slog.Bool("tls", xtls), + slog.String("listener", listenerName)) defer func() { c.conn.Close() diff --git a/import.go b/import.go index 2beb9c1..134b729 100644 --- a/import.go +++ b/import.go @@ -176,7 +176,11 @@ func importctl(ctx context.Context, ctl *ctl, mbox bool) { if mbox { kind = "mbox" } - ctl.log.Info("importing messages", slog.String("kind", kind), slog.String("account", account), slog.String("mailbox", mailbox), slog.String("source", src)) + ctl.log.Info("importing messages", + slog.String("kind", kind), + slog.String("account", account), + slog.String("mailbox", mailbox), + slog.String("source", src)) var err error var mboxf *os.File diff --git a/iprev/iprev.go b/iprev/iprev.go index 22be3bf..e9de926 100644 --- a/iprev/iprev.go +++ b/iprev/iprev.go @@ -63,7 +63,10 @@ func Lookup(ctx context.Context, resolver dns.Resolver, ip net.IP) (rstatus Stat start := time.Now() defer func() { metricIPRev.WithLabelValues(string(rstatus)).Observe(float64(time.Since(start)) / float64(time.Second)) - log.Debugx("iprev lookup result", rerr, slog.Any("ip", ip), slog.Any("status", rstatus), slog.Duration("duration", time.Since(start))) + log.Debugx("iprev lookup result", rerr, + slog.Any("ip", ip), + slog.Any("status", rstatus), + slog.Duration("duration", time.Since(start))) }() revNames, result, revErr := dns.WithPackage(resolver, "iprev").LookupAddr(ctx, ip.String()) diff --git a/junk/filter.go b/junk/filter.go index 471e576..57bf78a 100644 --- a/junk/filter.go +++ b/junk/filter.go @@ -378,7 +378,10 @@ func (f *Filter) ClassifyWords(ctx context.Context, words map[string]struct{}) ( expect[w] = struct{}{} } if len(unknowns) > 0 { - f.log.Debug("unknown words in bloom filter, showing max 50", slog.Any("words", unknowns), slog.Any("totalunknown", totalUnknown), slog.Any("totalwords", len(words))) + f.log.Debug("unknown words in bloom filter, showing max 50", + slog.Any("words", unknowns), + slog.Any("totalunknown", totalUnknown), + slog.Any("totalwords", len(words))) } // Fetch words from database. @@ -391,7 +394,10 @@ func (f *Filter) ClassifyWords(ctx context.Context, words map[string]struct{}) ( delete(expect, w) f.cache[w] = c } - f.log.Debug("unknown words in db", slog.Any("words", expect), slog.Any("totalunknown", len(expect)), slog.Any("totalwords", len(words))) + f.log.Debug("unknown words in db", + slog.Any("words", expect), + slog.Any("totalunknown", len(expect)), + slog.Any("totalwords", len(words))) } for w := range words { diff --git a/message/part.go b/message/part.go index 4cb6ae8..cf318fa 100644 --- a/message/part.go +++ b/message/part.go @@ -330,7 +330,10 @@ func newPart(log mlog.Log, strict bool, r io.ReaderAt, offset int64, parent *Par p.MediaType = "APPLICATION" p.MediaSubType = "OCTET-STREAM" } - log.Debugx("malformed content-type, attempting to recover and continuing", err, slog.String("contenttype", p.header.Get("Content-Type")), slog.String("mediatype", p.MediaType), slog.String("mediasubtype", p.MediaSubType)) + log.Debugx("malformed content-type, attempting to recover and continuing", err, + slog.String("contenttype", p.header.Get("Content-Type")), + slog.String("mediatype", p.MediaType), + slog.String("mediasubtype", p.MediaSubType)) } else if mt != "" { t := strings.SplitN(strings.ToUpper(mt), "/", 2) if len(t) != 2 { diff --git a/metrics/http.go b/metrics/http.go index 39c6b56..9fe2bf4 100644 --- a/metrics/http.go +++ b/metrics/http.go @@ -57,5 +57,9 @@ func HTTPClientObserve(ctx context.Context, log mlog.Log, pkg, method string, st result = "error" } metricHTTPClient.WithLabelValues(pkg, method, result, fmt.Sprintf("%d", statusCode)).Observe(float64(time.Since(start)) / float64(time.Second)) - log.Debugx("httpclient result", err, slog.String("pkg", pkg), slog.String("method", method), slog.Int("code", statusCode), slog.Duration("duration", time.Since(start))) + log.Debugx("httpclient result", err, + slog.String("pkg", pkg), + slog.String("method", method), + slog.Int("code", statusCode), + slog.Duration("duration", time.Since(start))) } diff --git a/mox-/admin.go b/mox-/admin.go index 30aff70..515e827 100644 --- a/mox-/admin.go +++ b/mox-/admin.go @@ -291,7 +291,10 @@ func DomainAdd(ctx context.Context, domain dns.Domain, accountName string, local log := pkglog.WithContext(ctx) defer func() { if rerr != nil { - log.Errorx("adding domain", rerr, slog.Any("domain", domain), slog.String("account", accountName), slog.Any("localpart", localpart)) + log.Errorx("adding domain", rerr, + slog.Any("domain", domain), + slog.String("account", accountName), + slog.Any("localpart", localpart)) } }() @@ -929,7 +932,10 @@ func DestinationSave(ctx context.Context, account, destName string, newDest conf log := pkglog.WithContext(ctx) defer func() { if rerr != nil { - log.Errorx("saving destination", rerr, slog.String("account", account), slog.String("destname", destName), slog.Any("destination", newDest)) + log.Errorx("saving destination", rerr, + slog.String("account", account), + slog.String("destname", destName), + slog.Any("destination", newDest)) } }() diff --git a/mox-/config.go b/mox-/config.go index 26b5869..026171a 100644 --- a/mox-/config.go +++ b/mox-/config.go @@ -568,10 +568,16 @@ func PrepareStaticConfig(ctx context.Context, log mlog.Log, configFile string, c key = findACMEHostPrivateKey(acmeName, host, keyType, 2) } if key != nil { - log.Debug("found existing private key for certificate for host", slog.String("acmename", acmeName), slog.String("host", host), slog.Any("keytype", keyType)) + log.Debug("found existing private key for certificate for host", + slog.String("acmename", acmeName), + slog.String("host", host), + slog.Any("keytype", keyType)) return key, nil } - log.Debug("generating new private key for certificate for host", slog.String("acmename", acmeName), slog.String("host", host), slog.Any("keytype", keyType)) + log.Debug("generating new private key for certificate for host", + slog.String("acmename", acmeName), + slog.String("host", host), + slog.Any("keytype", keyType)) switch keyType { case autocert.KeyRSA2048: return rsa.GenerateKey(cryptorand.Reader, 2048) @@ -657,7 +663,10 @@ func PrepareStaticConfig(ctx context.Context, log mlog.Log, configFile string, c switch k := privKey.(type) { case *rsa.PrivateKey: if k.N.BitLen() != 2048 { - log.Error("need rsa key with 2048 bits, for host private key for DANE/ACME certificates, ignoring", slog.String("listener", name), slog.String("file", keyPath), slog.Int("bits", k.N.BitLen())) + log.Error("need rsa key with 2048 bits, for host private key for DANE/ACME certificates, ignoring", + slog.String("listener", name), + slog.String("file", keyPath), + slog.Int("bits", k.N.BitLen())) continue } l.TLS.HostPrivateRSA2048Keys = append(l.TLS.HostPrivateRSA2048Keys, k) @@ -668,7 +677,10 @@ func PrepareStaticConfig(ctx context.Context, log mlog.Log, configFile string, c } l.TLS.HostPrivateECDSAP256Keys = append(l.TLS.HostPrivateECDSAP256Keys, k) default: - log.Error("unrecognized key type for host private key for DANE/ACME certificates, ignoring", slog.String("listener", name), slog.String("file", keyPath), slog.String("keytype", fmt.Sprintf("%T", privKey))) + log.Error("unrecognized key type for host private key for DANE/ACME certificates, ignoring", + slog.String("listener", name), + slog.String("file", keyPath), + slog.String("keytype", fmt.Sprintf("%T", privKey))) continue } } @@ -1318,7 +1330,10 @@ func prepareDynamicConfig(ctx context.Context, log mlog.Log, dynamicPath string, if !ok { addErrorf("could not find localpart %q to replace with address in destinations", lp) } else { - log.Error(`deprecation warning: support for account destination addresses specified as just localpart ("username") instead of full email address will be removed in the future; update domains.conf, for each Account, for each Destination, ensure each key is an email address by appending "@" and the default domain for the account`, slog.Any("localpart", lp), slog.Any("address", addr), slog.String("account", accName)) + log.Error(`deprecation warning: support for account destination addresses specified as just localpart ("username") instead of full email address will be removed in the future; update domains.conf, for each Account, for each Destination, ensure each key is an email address by appending "@" and the default domain for the account`, + slog.Any("localpart", lp), + slog.Any("address", addr), + slog.String("account", accName)) acc.Destinations[addr] = dest delete(acc.Destinations, lp) } diff --git a/mtasts/mtasts.go b/mtasts/mtasts.go index 4b7ff68..598457b 100644 --- a/mtasts/mtasts.go +++ b/mtasts/mtasts.go @@ -194,7 +194,10 @@ func LookupRecord(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, log := mlog.New("mtasts", elog) start := time.Now() defer func() { - log.Debugx("mtasts lookup result", rerr, slog.Any("domain", domain), slog.Any("record", rrecord), slog.Duration("duration", time.Since(start))) + log.Debugx("mtasts lookup result", rerr, + slog.Any("domain", domain), + slog.Any("record", rrecord), + slog.Duration("duration", time.Since(start))) }() // ../rfc/8461:289 @@ -265,7 +268,11 @@ func FetchPolicy(ctx context.Context, elog *slog.Logger, domain dns.Domain) (pol log := mlog.New("mtasts", elog) start := time.Now() defer func() { - log.Debugx("mtasts fetch policy result", rerr, slog.Any("domain", domain), slog.Any("policy", policy), slog.String("policytext", policyText), slog.Duration("duration", time.Since(start))) + log.Debugx("mtasts fetch policy result", rerr, + slog.Any("domain", domain), + slog.Any("policy", policy), + slog.String("policytext", policyText), + slog.Duration("duration", time.Since(start))) }() // Timeout of 1 minute. ../rfc/8461:569 @@ -335,7 +342,11 @@ func Get(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, domain d result := "lookuperror" defer func() { metricGet.WithLabelValues(result).Observe(float64(time.Since(start)) / float64(time.Second)) - log.Debugx("mtasts get result", err, slog.Any("domain", domain), slog.Any("record", record), slog.Any("policy", policy), slog.Duration("duration", time.Since(start))) + log.Debugx("mtasts get result", err, + slog.Any("domain", domain), + slog.Any("record", record), + slog.Any("policy", policy), + slog.Duration("duration", time.Since(start))) }() record, _, err = LookupRecord(ctx, log.Logger, resolver, domain) diff --git a/queue/direct.go b/queue/direct.go index 8d04d69..796fd3e 100644 --- a/queue/direct.go +++ b/queue/direct.go @@ -293,7 +293,10 @@ func deliverDirect(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale } // todo future: add a configuration option to not fall back? - nqlog.Info("connecting again for delivery attempt without tls", slog.Bool("enforcemtasts", enforceMTASTS), slog.Bool("tlsdane", tlsDANE), slog.Any("requiretls", m.RequireTLS)) + nqlog.Info("connecting again for delivery attempt without tls", + slog.Bool("enforcemtasts", enforceMTASTS), + slog.Bool("tlsdane", tlsDANE), + slog.Any("requiretls", m.RequireTLS)) permanent, _, _, secodeOpt, remoteIP, errmsg, _, ok = deliverHost(nqlog, resolver, dialer, ourHostname, transportName, h, enforceMTASTS, haveMX, origNextHopAuthentic, origNextHop, expandedNextHopAuthentic, expandedNextHop, &m, smtpclient.TLSSkip, false, &tlsrpt.Result{}) } diff --git a/queue/queue.go b/queue/queue.go index 600842c..5c77ded 100644 --- a/queue/queue.go +++ b/queue/queue.go @@ -525,7 +525,10 @@ func queueDelete(ctx context.Context, msgID int64) error { // The queue is updated, either by removing a delivered or permanently failed // message, or updating the time for the next attempt. A DSN may be sent. func deliver(log mlog.Log, resolver dns.Resolver, m Msg) { - qlog := log.WithCid(mox.Cid()).With(slog.Any("from", m.Sender()), slog.Any("recipient", m.Recipient()), slog.Int("attempts", m.Attempts), slog.Int64("msgid", m.ID)) + qlog := log.WithCid(mox.Cid()).With(slog.Any("from", m.Sender()), + slog.Any("recipient", m.Recipient()), + slog.Int("attempts", m.Attempts), + slog.Int64("msgid", m.ID)) defer func() { deliveryResult <- formatIPDomain(m.RecipientDomain) diff --git a/queue/submit.go b/queue/submit.go index d61d45e..aed3122 100644 --- a/queue/submit.go +++ b/queue/submit.go @@ -54,7 +54,15 @@ func deliverSubmit(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale var success bool defer func() { metricDelivery.WithLabelValues(fmt.Sprintf("%d", m.Attempts), transportName, string(tlsMode), deliveryResult).Observe(float64(time.Since(start)) / float64(time.Second)) - qlog.Debug("queue deliversubmit result", slog.Any("host", transport.DNSHost), slog.Int("port", port), slog.Int("attempt", m.Attempts), slog.Bool("permanent", permanent), slog.String("secodeopt", secodeOpt), slog.String("errmsg", errmsg), slog.Bool("ok", success), slog.Duration("duration", time.Since(start))) + qlog.Debug("queue deliversubmit result", + slog.Any("host", transport.DNSHost), + slog.Int("port", port), + slog.Int("attempt", m.Attempts), + slog.Bool("permanent", permanent), + slog.String("secodeopt", secodeOpt), + slog.String("errmsg", errmsg), + slog.Bool("ok", success), + slog.Duration("duration", time.Since(start))) }() // todo: SMTP-DANE should be used when relaying on port 25. diff --git a/serve_unix.go b/serve_unix.go index 8662781..0a5ca9a 100644 --- a/serve_unix.go +++ b/serve_unix.go @@ -90,7 +90,11 @@ func monitorDNSBL(log mlog.Log) { for _, zone := range zones { status, expl, err := dnsbl.Lookup(mox.Context, log.Logger, resolver, zone, ip) if err != nil { - log.Errorx("dnsbl monitor lookup", err, slog.Any("ip", ip), slog.Any("zone", zone), slog.String("expl", expl), slog.Any("status", status)) + log.Errorx("dnsbl monitor lookup", err, + slog.Any("ip", ip), + slog.Any("zone", zone), + slog.String("expl", expl), + slog.Any("status", status)) } k := key{zone, ip.String()} @@ -161,7 +165,11 @@ Only implemented on unix systems, not Windows. domainsconf, err := filepath.Abs(mox.ConfigDynamicPath) log.Check(err, "finding absolute domains.conf path") - log.Print("starting as root, initializing network listeners", slog.String("version", moxvar.Version), slog.Any("pid", os.Getpid()), slog.String("moxconf", moxconf), slog.String("domainsconf", domainsconf)) + log.Print("starting as root, initializing network listeners", + slog.String("version", moxvar.Version), + slog.Any("pid", os.Getpid()), + slog.String("moxconf", moxconf), + slog.String("domainsconf", domainsconf)) if os.Getenv("MOX_SOCKETS") != "" { log.Fatal("refusing to start as root with $MOX_SOCKETS set") } @@ -187,7 +195,11 @@ Only implemented on unix systems, not Windows. } else { mox.RestorePassedFiles() mox.MustLoadConfig(true, checkACMEHosts) - log.Print("starting as unprivileged user", slog.String("user", mox.Conf.Static.User), slog.Any("uid", mox.Conf.Static.UID), slog.Any("gid", mox.Conf.Static.GID), slog.Any("pid", os.Getpid())) + log.Print("starting as unprivileged user", + slog.String("user", mox.Conf.Static.User), + slog.Any("uid", mox.Conf.Static.UID), + slog.Any("gid", mox.Conf.Static.GID), + slog.Any("pid", os.Getpid())) } syscall.Umask(syscall.Umask(007) | 007) @@ -205,7 +217,10 @@ Only implemented on unix systems, not Windows. log.Fatalx("writing recvidpath", err, slog.String("path", recvidpath)) } err := os.Chown(recvidpath, int(mox.Conf.Static.UID), 0) - log.Check(err, "chown receveidid.key", slog.String("path", recvidpath), slog.Any("uid", mox.Conf.Static.UID), slog.Any("gid", 0)) + log.Check(err, "chown receveidid.key", + slog.String("path", recvidpath), + slog.Any("uid", mox.Conf.Static.UID), + slog.Any("gid", 0)) err = os.Chmod(recvidpath, 0640) log.Check(err, "chmod receveidid.key to 0640", slog.String("path", recvidpath)) } @@ -308,7 +323,10 @@ Only implemented on unix systems, not Windows. log.Errorx("changelog delivery", err) return next } - log.Info("delivered changelog", slog.Any("current", current), slog.Any("lastknown", lastknown), slog.Any("latest", latest)) + log.Info("delivered changelog", + slog.Any("current", current), + slog.Any("lastknown", lastknown), + slog.Any("latest", latest)) if err := mox.StoreLastKnown(latest); err != nil { // This will be awkward, we'll keep notifying the postmaster once every 24h... log.Infox("updating last known version", err) @@ -485,11 +503,19 @@ func fixperms(log mlog.Log, workdir, configdir, datadir string, moxuid, moxgid u for _, ch := range changes { if ch.uid != nil { err := os.Chown(ch.path, int(*ch.uid), int(*ch.gid)) - log.Printx("chown, fixing uid/gid", err, slog.String("path", ch.path), slog.Any("olduid", ch.olduid), slog.Any("oldgid", ch.oldgid), slog.Any("newuid", *ch.uid), slog.Any("newgid", *ch.gid)) + log.Printx("chown, fixing uid/gid", err, + slog.String("path", ch.path), + slog.Any("olduid", ch.olduid), + slog.Any("oldgid", ch.oldgid), + slog.Any("newuid", *ch.uid), + slog.Any("newgid", *ch.gid)) } if ch.mode != nil { err := os.Chmod(ch.path, *ch.mode) - log.Printx("chmod, fixing permissions", err, slog.String("path", ch.path), slog.Any("oldmode", fmt.Sprintf("%03o", ch.oldmode)), slog.Any("newmode", fmt.Sprintf("%03o", *ch.mode))) + log.Printx("chmod, fixing permissions", err, + slog.String("path", ch.path), + slog.Any("oldmode", fmt.Sprintf("%03o", ch.oldmode)), + slog.Any("newmode", fmt.Sprintf("%03o", *ch.mode))) } } @@ -511,7 +537,12 @@ func fixperms(log mlog.Log, workdir, configdir, datadir string, moxuid, moxgid u } if st.Uid != moxuid || st.Gid != root { err := os.Chown(path, int(moxuid), root) - log.Printx("walk chown, fixing uid/gid", err, slog.String("path", path), slog.Any("olduid", st.Uid), slog.Any("oldgid", st.Gid), slog.Any("newuid", moxuid), slog.Any("newgid", root)) + log.Printx("walk chown, fixing uid/gid", err, + slog.String("path", path), + slog.Any("olduid", st.Uid), + slog.Any("oldgid", st.Gid), + slog.Any("newuid", moxuid), + slog.Any("newgid", root)) } omode := fi.Mode() & (fs.ModeSetgid | 0777) var nmode fs.FileMode @@ -522,7 +553,10 @@ func fixperms(log mlog.Log, workdir, configdir, datadir string, moxuid, moxgid u } if omode != nmode { err := os.Chmod(path, nmode) - log.Printx("walk chmod, fixing permissions", err, slog.String("path", path), slog.Any("oldmode", fmt.Sprintf("%03o", omode)), slog.Any("newmode", fmt.Sprintf("%03o", nmode))) + log.Printx("walk chmod, fixing permissions", err, + slog.String("path", path), + slog.Any("oldmode", fmt.Sprintf("%03o", omode)), + slog.Any("newmode", fmt.Sprintf("%03o", nmode))) } return nil }) diff --git a/smtpclient/client.go b/smtpclient/client.go index 93d925d..a3ca81f 100644 --- a/smtpclient/client.go +++ b/smtpclient/client.go @@ -282,7 +282,10 @@ func New(ctx context.Context, elog *slog.Logger, conn net.Conn, tlsMode TLSMode, c.tlsResultAdd(1, 0, nil) c.conn = tlsconn tlsversion, ciphersuite := mox.TLSInfo(tlsconn) - c.log.Debug("tls client handshake done", slog.String("tls", tlsversion), slog.String("ciphersuite", ciphersuite), slog.Any("servername", remoteHostname)) + c.log.Debug("tls client handshake done", + slog.String("tls", tlsversion), + slog.String("ciphersuite", ciphersuite), + slog.Any("servername", remoteHostname)) c.tls = true } else { c.conn = conn @@ -545,7 +548,11 @@ func (c *Client) readecode(ecodes bool) (code int, secode, lastLine string, text } } metricCommands.WithLabelValues(cmd, fmt.Sprintf("%d", co), sec).Observe(float64(time.Since(c.cmdStart)) / float64(time.Second)) - c.log.Debug("smtpclient command result", slog.String("cmd", cmd), slog.Int("code", co), slog.String("secode", sec), slog.Duration("duration", time.Since(c.cmdStart))) + c.log.Debug("smtpclient command result", + slog.String("cmd", cmd), + slog.Int("code", co), + slog.String("secode", sec), + slog.Duration("duration", time.Since(c.cmdStart))) } return co, sec, line, texts, nil } diff --git a/smtpclient/dial.go b/smtpclient/dial.go index 55dd591..809b855 100644 --- a/smtpclient/dial.go +++ b/smtpclient/dial.go @@ -76,12 +76,18 @@ func Dial(ctx context.Context, elog *slog.Logger, dialer Dialer, host dns.IPDoma } conn, err := dial(ctx, dialer, timeout, addr, laddr) if err == nil { - log.Debug("connected to host", slog.Any("host", host), slog.String("addr", addr), slog.Any("laddr", laddr)) + log.Debug("connected to host", + slog.Any("host", host), + slog.String("addr", addr), + slog.Any("laddr", laddr)) name := host.String() dialedIPs[name] = append(dialedIPs[name], ip) return conn, ip, nil } - log.Debugx("connection attempt", err, slog.Any("host", host), slog.String("addr", addr), slog.Any("laddr", laddr)) + log.Debugx("connection attempt", err, + slog.Any("host", host), + slog.String("addr", addr), + slog.Any("laddr", laddr)) lastErr = err lastIP = ip } diff --git a/smtpclient/gather.go b/smtpclient/gather.go index cfb5c48..a680fa6 100644 --- a/smtpclient/gather.go +++ b/smtpclient/gather.go @@ -301,7 +301,10 @@ func GatherTLSA(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, h } daneRequired = len(l) > 0 l = filterUsableTLSARecords(log, l) - log.Debug("tlsa records exist", slog.Bool("danerequired", daneRequired), slog.Any("records", l), slog.Any("basedomain", tlsaBaseDomain)) + log.Debug("tlsa records exist", + slog.Bool("danerequired", daneRequired), + slog.Any("records", l), + slog.Any("basedomain", tlsaBaseDomain)) return daneRequired, l, tlsaBaseDomain, err } @@ -333,7 +336,10 @@ func lookupTLSACNAME(ctx context.Context, log mlog.Log, resolver dns.Resolver, p var err error l, result, err = resolver.LookupTLSA(ctx, 0, "", name) if dns.IsNotFound(err) || err == nil && len(l) == 0 { - log.Debugx("no tlsa records for host, not doing dane", err, slog.Any("host", host), slog.String("name", name), slog.Bool("authentic", result.Authentic)) + log.Debugx("no tlsa records for host, not doing dane", err, + slog.Any("host", host), + slog.String("name", name), + slog.Bool("authentic", result.Authentic)) return nil, nil } else if err != nil { return nil, fmt.Errorf("looking up tlsa records for tlsa candidate base domain: %w", err) diff --git a/smtpserver/analyze.go b/smtpserver/analyze.go index 7370544..0f22819 100644 --- a/smtpserver/analyze.go +++ b/smtpserver/analyze.go @@ -302,7 +302,10 @@ func analyze(ctx context.Context, log mlog.Log, resolver dns.Resolver, d deliver log.Infox("determining reputation", err, slog.Any("message", d.m)) return reject(smtp.C451LocalErr, smtp.SeSys3Other0, "error processing", err, reasonReputationError) } - log.Info("reputation analyzed", slog.Bool("conclusive", conclusive), slog.Any("isjunk", isjunk), slog.String("method", string(method))) + log.Info("reputation analyzed", + slog.Bool("conclusive", conclusive), + slog.Any("isjunk", isjunk), + slog.String("method", string(method))) if conclusive { if !*isjunk { return analysis{accept: true, mailbox: mailbox, dmarcReport: dmarcReport, tlsReport: tlsReport, reason: reason, dmarcOverrideReason: dmarcOverrideReason, headers: headers} @@ -414,7 +417,10 @@ func analyze(ctx context.Context, log mlog.Log, resolver dns.Resolver, d deliver } accept = contentProb <= threshold junkSubjectpass = contentProb < threshold-0.2 - log.Info("content analyzed", slog.Bool("accept", accept), slog.Float64("contentprob", contentProb), slog.Bool("subjectpass", junkSubjectpass)) + log.Info("content analyzed", + slog.Bool("accept", accept), + slog.Float64("contentprob", contentProb), + slog.Bool("subjectpass", junkSubjectpass)) } else if err != store.ErrNoJunkFilter { log.Errorx("open junkfilter", err) return reject(smtp.C451LocalErr, smtp.SeSys3Other0, "error processing", err, reasonJunkFilterError) diff --git a/smtpserver/reputation.go b/smtpserver/reputation.go index d9429f6..45bb05b 100644 --- a/smtpserver/reputation.go +++ b/smtpserver/reputation.go @@ -143,7 +143,10 @@ func reputation(tx *bstore.Tx, log mlog.Log, m *store.Message) (rjunk *bool, rco xmessageList := func(q *bstore.Query[store.Message], descr string) []store.Message { t0 := time.Now() l, err := q.List() - log.Debugx("querying messages for reputation", err, slog.Int("msgs", len(l)), slog.String("descr", descr), slog.Duration("queryduration", time.Since(t0))) + log.Debugx("querying messages for reputation", err, + slog.Int("msgs", len(l)), + slog.String("descr", descr), + slog.Duration("queryduration", time.Since(t0))) if err != nil { panic(queryError(fmt.Sprintf("listing messages: %v", err))) } diff --git a/smtpserver/server.go b/smtpserver/server.go index df92af8..15b05dd 100644 --- a/smtpserver/server.go +++ b/smtpserver/server.go @@ -233,7 +233,10 @@ func listen1(protocol, name, ip string, port int, hostname dns.Domain, tlsConfig log := mlog.New("smtpserver", nil) addr := net.JoinHostPort(ip, fmt.Sprintf("%d", port)) if os.Getuid() == 0 { - log.Print("listening for smtp", slog.String("listener", name), slog.String("address", addr), slog.String("protocol", protocol)) + log.Print("listening for smtp", + slog.String("listener", name), + slog.String("address", addr), + slog.String("protocol", protocol)) } network := mox.Network(ip) ln, err := mox.Listen(network, addr) @@ -476,7 +479,12 @@ func (c *conn) bwritecodeline(code int, secode string, msg string, err error) { ecode = fmt.Sprintf("%d.%s", code/100, secode) } metricCommands.WithLabelValues(c.kind(), c.cmd, fmt.Sprintf("%d", code), ecode).Observe(float64(time.Since(c.cmdStart)) / float64(time.Second)) - c.log.Debugx("smtp command result", err, slog.String("kind", c.kind()), slog.String("cmd", c.cmd), slog.Int("code", code), slog.String("ecode", ecode), slog.Duration("duration", time.Since(c.cmdStart))) + c.log.Debugx("smtp command result", err, + slog.String("kind", c.kind()), + slog.String("cmd", c.cmd), + slog.Int("code", code), + slog.String("ecode", ecode), + slog.Duration("duration", time.Since(c.cmdStart))) var sep string if ecode != "" { @@ -584,7 +592,12 @@ func serve(listenerName string, cid int64, hostname dns.Domain, tlsConfig *tls.C c.w = bufio.NewWriter(c.tw) metricConnection.WithLabelValues(c.kind()).Inc() - c.log.Info("new connection", slog.Any("remote", c.conn.RemoteAddr()), slog.Any("local", c.conn.LocalAddr()), slog.Bool("submission", submission), slog.Bool("tls", tls), slog.String("listener", listenerName)) + c.log.Info("new connection", + slog.Any("remote", c.conn.RemoteAddr()), + slog.Any("local", c.conn.LocalAddr()), + slog.Bool("submission", submission), + slog.Bool("tls", tls), + slog.String("listener", listenerName)) defer func() { c.origConn.Close() // Close actual TCP socket, regardless of TLS on top. @@ -1897,7 +1910,11 @@ func (c *conn) submit(ctx context.Context, recvHdrFor func(string) string, msgWr xsmtpServerErrorf(errCodes(smtp.C451LocalErr, smtp.SeSys3Other0, err), "error delivering message: %v", err) } metricSubmission.WithLabelValues("ok").Inc() - c.log.Info("message queued for delivery", slog.Any("mailfrom", *c.mailFrom), slog.Any("rcptto", rcptAcc.rcptTo), slog.Bool("smtputf8", c.smtputf8), slog.Int64("msgsize", msgSize)) + c.log.Info("message queued for delivery", + slog.Any("mailfrom", *c.mailFrom), + slog.Any("rcptto", rcptAcc.rcptTo), + slog.Bool("smtputf8", c.smtputf8), + slog.Int64("msgsize", msgSize)) err := c.account.DB.Insert(ctx, &store.Outgoing{Recipient: rcptAcc.rcptTo.XString(true)}) xcheckf(err, "adding outgoing message") @@ -2150,7 +2167,13 @@ func (c *conn) deliver(ctx context.Context, recvHdrFor func(string) string, msgW errmsg = r.Err.Error() } authResAddDKIM(string(r.Status), comment, errmsg, props) - c.log.Debugx("dkim verification result", r.Err, slog.Int("index", i), slog.Any("mailfrom", c.mailFrom), slog.Any("status", r.Status), slog.Any("domain", domain), slog.Any("selector", selector), slog.Any("identity", identity)) + c.log.Debugx("dkim verification result", r.Err, + slog.Int("index", i), + slog.Any("mailfrom", c.mailFrom), + slog.Any("status", r.Status), + slog.Any("domain", domain), + slog.Any("selector", selector), + slog.Any("identity", identity)) } // Add SPF results to Authentication-Results header. ../rfc/7208:2141 @@ -2307,7 +2330,12 @@ func (c *conn) deliver(ctx context.Context, recvHdrFor func(string) string, msgW var deliverErrors []deliverError addError := func(rcptAcc rcptAccount, code int, secode string, userError bool, errmsg string) { e := deliverError{rcptAcc.rcptTo, code, secode, userError, errmsg} - c.log.Info("deliver error", slog.Any("rcptto", e.rcptTo), slog.Int("code", code), slog.String("secode", "secode"), slog.Bool("usererror", userError), slog.String("errmsg", errmsg)) + c.log.Info("deliver error", + slog.Any("rcptto", e.rcptTo), + slog.Int("code", code), + slog.String("secode", "secode"), + slog.Bool("usererror", userError), + slog.String("errmsg", errmsg)) deliverErrors = append(deliverErrors, e) } diff --git a/spf/spf.go b/spf/spf.go index 8f39476..49784d4 100644 --- a/spf/spf.go +++ b/spf/spf.go @@ -133,7 +133,11 @@ func Lookup(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, domai log := mlog.New("spf", elog) start := time.Now() defer func() { - log.Debugx("spf lookup result", rerr, slog.Any("domain", domain), slog.Any("status", rstatus), slog.Any("record", rrecord), slog.Duration("duration", time.Since(start))) + log.Debugx("spf lookup result", rerr, + slog.Any("domain", domain), + slog.Any("status", rstatus), + slog.Any("record", rrecord), + slog.Duration("duration", time.Since(start))) }() // ../rfc/7208:586 @@ -199,7 +203,12 @@ func Verify(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, args start := time.Now() defer func() { metricSPFVerify.WithLabelValues(string(received.Result)).Observe(float64(time.Since(start)) / float64(time.Second)) - log.Debugx("spf verify result", rerr, slog.Any("domain", args.domain), slog.Any("ip", args.RemoteIP), slog.Any("status", received.Result), slog.String("explanation", explanation), slog.Duration("duration", time.Since(start))) + log.Debugx("spf verify result", rerr, + slog.Any("domain", args.domain), + slog.Any("ip", args.RemoteIP), + slog.Any("status", received.Result), + slog.String("explanation", explanation), + slog.Duration("duration", time.Since(start))) }() isHello, ok := prepare(&args) @@ -298,7 +307,14 @@ func Evaluate(ctx context.Context, elog *slog.Logger, record *Record, resolver d func evaluate(ctx context.Context, log mlog.Log, record *Record, resolver dns.Resolver, args Args) (rstatus Status, mechanism, rexplanation string, rauthentic bool, rerr error) { start := time.Now() defer func() { - log.Debugx("spf evaluate result", rerr, slog.Int("dnsrequests", *args.dnsRequests), slog.Int("voidlookups", *args.voidLookups), slog.Any("domain", args.domain), slog.Any("status", rstatus), slog.String("mechanism", mechanism), slog.String("explanation", rexplanation), slog.Duration("duration", time.Since(start))) + log.Debugx("spf evaluate result", rerr, + slog.Int("dnsrequests", *args.dnsRequests), + slog.Int("voidlookups", *args.voidLookups), + slog.Any("domain", args.domain), + slog.Any("status", rstatus), + slog.String("mechanism", mechanism), + slog.String("explanation", rexplanation), + slog.Duration("duration", time.Since(start))) }() if args.dnsRequests == nil { diff --git a/store/train.go b/store/train.go index b1e96b3..72b6311 100644 --- a/store/train.go +++ b/store/train.go @@ -98,7 +98,11 @@ func (a *Account) RetrainMessage(ctx context.Context, log mlog.Log, tx *bstore.T return nil } - log.Debug("updating junk filter", slog.Bool("untrain", untrain), slog.Bool("untrainjunk", untrainJunk), slog.Bool("train", train), slog.Bool("trainjunk", trainJunk)) + log.Debug("updating junk filter", + slog.Bool("untrain", untrain), + slog.Bool("untrainjunk", untrainJunk), + slog.Bool("train", train), + slog.Bool("trainjunk", trainJunk)) mr := a.MessageReader(*m) defer func() { diff --git a/tlsrpt/lookup.go b/tlsrpt/lookup.go index 26b633c..db5e2ce 100644 --- a/tlsrpt/lookup.go +++ b/tlsrpt/lookup.go @@ -54,7 +54,10 @@ func Lookup(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, domai } } metricLookup.WithLabelValues(result).Observe(float64(time.Since(start)) / float64(time.Second)) - log.Debugx("tlsrpt lookup result", rerr, slog.Any("domain", domain), slog.Any("record", rrecord), slog.Duration("duration", time.Since(start))) + log.Debugx("tlsrpt lookup result", rerr, + slog.Any("domain", domain), + slog.Any("record", rrecord), + slog.Duration("duration", time.Since(start))) }() name := "_smtp._tls." + domain.ASCII + "." diff --git a/tlsrptsend/send.go b/tlsrptsend/send.go index e80094b..378b7de 100644 --- a/tlsrptsend/send.go +++ b/tlsrptsend/send.go @@ -236,7 +236,9 @@ func sendReports(ctx context.Context, log mlog.Log, resolver dns.Resolver, db *b }() defer wg.Done() - rlog := log.WithCid(mox.Cid()).With(slog.String("policydomain", k.policyDomain), slog.String("daytutc", k.dayUTC), slog.Bool("isrcptdom", isRcptDom)) + rlog := log.WithCid(mox.Cid()).With(slog.String("policydomain", k.policyDomain), + slog.String("daytutc", k.dayUTC), + slog.Bool("isrcptdom", isRcptDom)) rlog.Info("looking to send tls report for domain") cleanup, err := sendReportDomain(ctx, rlog, resolver, db, endTimeUTC, isRcptDom, k.policyDomain, k.dayUTC) if err != nil { diff --git a/updates/updates.go b/updates/updates.go index 95a875b..e837e29 100644 --- a/updates/updates.go +++ b/updates/updates.go @@ -90,7 +90,11 @@ func Lookup(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, domai result = "error" } metricLookup.WithLabelValues(result).Observe(float64(time.Since(start)) / float64(time.Second)) - log.Debugx("updates lookup result", rerr, slog.Any("domain", domain), slog.Any("version", rversion), slog.Any("record", rrecord), slog.Duration("duration", time.Since(start))) + log.Debugx("updates lookup result", rerr, + slog.Any("domain", domain), + slog.Any("version", rversion), + slog.Any("record", rrecord), + slog.Duration("duration", time.Since(start))) }() nctx, cancel := context.WithTimeout(ctx, 30*time.Second) @@ -141,7 +145,10 @@ func FetchChangelog(ctx context.Context, elog *slog.Logger, baseURL string, base result = "error" } metricFetchChangelog.WithLabelValues(result).Observe(float64(time.Since(start)) / float64(time.Second)) - log.Debugx("updates fetch changelog result", rerr, slog.String("baseurl", baseURL), slog.Any("base", base), slog.Duration("duration", time.Since(start))) + log.Debugx("updates fetch changelog result", rerr, + slog.String("baseurl", baseURL), + slog.Any("base", base), + slog.Duration("duration", time.Since(start))) }() url := baseURL + "?from=" + base.String() @@ -186,7 +193,13 @@ func Check(ctx context.Context, elog *slog.Logger, resolver dns.Resolver, domain log := mlog.New("updates", elog) start := time.Now() defer func() { - log.Debugx("updates check result", rerr, slog.Any("domain", domain), slog.Any("lastknown", lastKnown), slog.String("changelogbaseurl", changelogBaseURL), slog.Any("version", rversion), slog.Any("record", rrecord), slog.Duration("duration", time.Since(start))) + log.Debugx("updates check result", rerr, + slog.Any("domain", domain), + slog.Any("lastknown", lastKnown), + slog.String("changelogbaseurl", changelogBaseURL), + slog.Any("version", rversion), + slog.Any("record", rrecord), + slog.Duration("duration", time.Since(start))) }() latest, record, err := Lookup(ctx, log.Logger, resolver, domain)