xmpp-certwatch

Add lots of logs rss
created pr with xmpp-certwatch/add-logging.1 on 2026-10-26T13:45:19Z · by 3c31bc8c
added xmpp-certwatch/add-logging.2 on 2026-10-26T13:54:49Z · by 3c31bc8c
1: 92fa143 ! 1: cfa444f Add lots of logs
commented on 2026-10-26T13:56:39Z · by 3c31bc8c
https://tangled.org/mrry.band/xmpp-certwatch add-logging
cmds
checkout latest patchset: 
ssh pr.pico.sh pull xmpp-certwatch:add-logging | git am -3
checkout specific patchset revision: 
ssh pr.pico.sh pull xmpp-certwatch:add-logging [rev] | git am -3
add changes to patch request: 
git format-patch main --stdout | ssh pr.pico.sh xmpp-certwatch:add-logging
add comment to patch request: 
ssh pr.pico.sh comment xmpp-certwatch:add-logging "lgtm!"

Patchset xmpp-certwatch/add-logging.2 on 2026-10-26T13:54:49Z · commit cfa444f

→ Add lots of logs
Eric Roberts 2026-10-26T13:41:20Z
+30 -6 cmd/cron/main.go #
......@@ -47,6 +47,7 @@ var xmppSession *xmpp.Session
4747 var pubsubService jid.JID
4848
4949 func publish(node string, title string) {
50+ log.Printf("Publishing notification: node=%s", node)
5051 entryId := uuid.New().String()
5152 _, err := pubsub.PublishIQ(
5253 context.Background(),
......@@ -57,15 +58,19 @@ func publish(node string, title string) {
5758 atomEntry(entryId, title),
5859 )
5960 if err != nil {
60- log.Printf("Error publishing to %s", node, err)
61+ log.Printf("Error publishing to %s: %s", node, err)
62+ } else {
63+ log.Printf("Published notification: node=%s", node)
6164 }
6265 }
6366
6467 func main() {
68+ log.Print("Cron started")
6569 opt, err := redis.ParseURL(os.Getenv("REDIS_URL"))
6670 if err != nil {
6771 log.Panic(err)
6872 }
73+ log.Print("Connecting XMPP session")
6974 xmppSession, err = DialXMPP(
7075 context.Background(),
7176 jid.MustParse(os.Args[1]),
......@@ -76,37 +81,56 @@ func main() {
7681 if err != nil {
7782 log.Panic(err)
7883 }
79- go func () {
84+ log.Print("XMPP session connected")
85+ go func() {
86+ log.Print("Serving XMPP session")
8087 err := xmppSession.Serve(nil)
8188 log.Printf("XMPP session error: %s\n", err)
8289 os.Exit(1)
8390 }()
8491 pubsubService = jid.MustParse(os.Args[3])
8592 rclient := redis.NewClient(opt)
93+ log.Print("Loading hosts from Redis")
8694 hosts := rclient.HGetAll(context.Background(), "mitm_monitor_hosts").Val()
95+ log.Printf("Loaded %d hosts from Redis", len(hosts))
96+ checked := 0
8797 for host, errCount := range hosts {
98+ log.Printf("Checking host: host=%s progress=%d/%d", host, checked+1, len(hosts))
8899 result := CheckOne(host)
100+ log.Printf("Host check returned: host=%s", host)
89101 if result.Err != nil {
90102 log.Printf("Error checking %s: %s\n", host, result.Err)
91- errCount, _ := rclient.HIncrBy(context.Background(), "mitm_monitor_hosts", host, 1).Result()
103+ errCount := updateErrorCount(rclient, host, 1)
92104 if errCount > 1 {
93105 publish(host, fmt.Sprintf("Error checking %s: %s", host, result.Err))
94106 }
95107 } else if !result.Dnssec {
96108 log.Printf("No DNSSEC for %s\n", host)
97- rclient.HIncrBy(context.Background(), "mitm_monitor_hosts", host, 2)
109+ updateErrorCount(rclient, host, 2)
98110 publish(host, fmt.Sprintf("DNSSEC failed for %s", host))
99111 } else if !result.Daneok {
100112 log.Printf("DANE failed for %s\n", host)
101- rclient.HIncrBy(context.Background(), "mitm_monitor_hosts", host, 2)
113+ updateErrorCount(rclient, host, 2)
102114 publish(host, fmt.Sprintf("Certificate check failed for %s: possible MITM or you changed your public key", host))
103115 } else {
104116 log.Printf("Success for %s\n", host)
105- rclient.HSet(context.Background(), "mitm_monitor_hosts", host, 0)
117+ log.Printf("Resetting Redis error count: host=%s", host)
118+ err := rclient.HSet(context.Background(), "mitm_monitor_hosts", host, 0).Err()
119+ log.Printf("Redis error count reset returned: host=%s error=%v", host, err)
106120 errCountI, _ := strconv.Atoi(errCount)
107121 if errCountI > 1 {
108122 publish(host, fmt.Sprintf("Certificate checks passed for %s", host))
109123 }
110124 }
125+ checked++
126+ log.Printf("Finished host: host=%s progress=%d/%d", host, checked, len(hosts))
111127 }
128+ log.Printf("Cron completed: hosts=%d", checked)
129+}
130+
131+func updateErrorCount(client *redis.Client, host string, increment int64) int64 {
132+ log.Printf("Updating Redis error count: host=%s increment=%d", host, increment)
133+ count, err := client.HIncrBy(context.Background(), "mitm_monitor_hosts", host, increment).Result()
134+ log.Printf("Redis error count update returned: host=%s count=%d error=%v", host, count, err)
135+ return count
112136 }
+17 -2 common/common.go #
......@@ -4,6 +4,7 @@ import (
44 "context"
55 "crypto/tls"
66 "fmt"
7+ "log"
78 "net"
89 "strings"
910 "time"
......@@ -73,6 +74,7 @@ func oneTarget(resolver *dane.Resolver, service string, selector string, target
7374 alpn = "xmpp-server"
7475 }
7576
77+ log.Printf("Resolving target addresses: service=%s selector=%s target=%s port=%d", service, selector, target, port)
7678 iplist, err := GetAddresses(resolver, target)
7779 if err != nil {
7880 return TargetResult{}, err
......@@ -83,8 +85,11 @@ func oneTarget(resolver *dane.Resolver, service string, selector string, target
8385 }
8486
8587 daneok := true
88+ log.Printf("Looking up TLSA: service=%s target=%s port=%d", service, target, port)
89+
8690 tlsa, err := dane.GetTLSA(resolver, target, int(port))
8791
92+ log.Printf("TLSA lookup returned: target=%s port=%d error=%v", target, port, err)
8893 if err != nil {
8994 return TargetResult{}, err
9095 }
......@@ -92,19 +97,25 @@ func oneTarget(resolver *dane.Resolver, service string, selector string, target
9297 infos := map[string]dane.TLSAinfo{}
9398 for _, ip := range iplist.IPs {
9499 // Ignore ygg targets for now
95- if strings.HasPrefix(fmt.Sprintf("%s", ip), "200:") { continue }
100+ if strings.HasPrefix(fmt.Sprintf("%s", ip), "200:") {
101+ log.Printf("Skipping Yggdrasil address: service=%s target=%s ip=%s port=%d", service, target, ip, port)
102+ continue
103+ }
96104 config := getDaneConfig(service, appname, alpn, service, ip, port)
97105 config.SetTLSA(tlsa)
98106
107+ log.Printf("Connecting target: service=%s selector=%s target=%s ip=%s port=%d starttls=%t", service, selector, target, ip, port, appname != "")
99108 if appname == "" {
100109 conn, err = dane.DialTLS(config)
101110 if err == nil {
111+ log.Printf("Starting TLS handshake: target=%s ip=%s port=%d", target, ip, port)
102112 err = conn.Handshake()
103113 }
104114 } else {
105115 conn, err = dane.DialStartTLS(config)
106116 }
107117
118+ log.Printf("Target connection returned: target=%s ip=%s port=%d error=%v", target, ip, port, err)
108119 if err != nil {
109120 return TargetResult{}, err
110121 }
......@@ -142,7 +153,9 @@ func oneTarget(resolver *dane.Resolver, service string, selector string, target
142153
143154 infos[fmt.Sprintf("%s:%d", ip, port)] = oneTlsa
144155
145- conn.Close()
156+ log.Printf("Closing target connection: target=%s ip=%s port=%d", target, ip, port)
157+ closeErr := conn.Close()
158+ log.Printf("Target connection close returned: target=%s ip=%s port=%d error=%v", target, ip, port, closeErr)
146159
147160 if config.DiagError != nil && config.DiagError.Error() != "DANE TLS authentication failed" {
148161 return TargetResult{}, config.DiagError
......@@ -168,6 +181,7 @@ type CheckResult struct {
168181
169182 func CheckOne(hostname string) CheckResult {
170183 finalResult := CheckResult{hostname, true, true, true, false, map[string]dane.TLSAinfo{}, nil}
184+ log.Printf("Initializing resolver: host=%s", hostname)
171185 resolver, err := dane.GetResolver("")
172186 if err != nil {
173187 finalResult.Err = err
......@@ -178,6 +192,7 @@ func CheckOne(hostname string) CheckResult {
178192 resolver.IPv6 = true
179193 resolver.IPv4 = true
180194
195+ log.Printf("Looking up SRV records: host=%s", hostname)
181196 allSrvs, err := GetSRV(resolver, hostname)
182197
183198 if err != nil {
+5 -0 common/dns.go #
......@@ -3,6 +3,7 @@ package common
33 import (
44 "errors"
55 "fmt"
6+ "log"
67 "net"
78 "strings"
89
......@@ -54,7 +55,9 @@ func sendQueryUDP(query *dane.Query, resolver *dane.Resolver) (*dns.Msg, error)
5455 retries := resolver.Retries
5556 for retries > 0 {
5657 for _, server := range resolver.Servers {
58+ log.Printf("DNS query started: transport=udp name=%s type=%s server=%s attempt=%d", query.Name, dns.TypeToString[query.Type], server.Address(), resolver.Retries-retries+1)
5759 response, _, err = c.Exchange(m, server.Address())
60+ log.Printf("DNS query returned: transport=udp name=%s type=%s server=%s error=%v", query.Name, dns.TypeToString[query.Type], server.Address(), err)
5861 if err == nil {
5962 return response, err
6063 }
......@@ -81,7 +84,9 @@ func sendQueryTCP(query *dane.Query, resolver *dane.Resolver) (*dns.Msg, error)
8184 c.Timeout = resolver.Timeout
8285
8386 for _, server := range resolver.Servers {
87+ log.Printf("DNS query started: transport=tcp name=%s type=%s server=%s", query.Name, dns.TypeToString[query.Type], server.Address())
8488 response, _, err = c.Exchange(m, server.Address())
89+ log.Printf("DNS query returned: transport=tcp name=%s type=%s server=%s error=%v", query.Name, dns.TypeToString[query.Type], server.Address(), err)
8590 if err == nil {
8691 return response, err
8792 }
Back to top