Merge pull request #6 from mastodon/fix-logging

Change logging library to be consistent with FCM relay (and fix log levels)

go.mod

@@ -30,6 +30,7 @@ require (
 	github.com/philhofer/fwd v1.1.2 // indirect
 	github.com/pkg/errors v0.9.1 // indirect
 	github.com/secure-systems-lab/go-securesystemslib v0.8.0 // indirect
+	github.com/sirupsen/logrus v1.9.3 // indirect
 	github.com/tinylib/msgp v1.1.9 // indirect
 	go.uber.org/atomic v1.11.0 // indirect
 	golang.org/x/crypto v0.22.0 // indirect

go.sum

@@ -78,6 +78,8 @@ github.com/secure-systems-lab/go-securesystemslib v0.8.0/go.mod h1:UH2VZVuJfCYR8
 github.com/sideshow/apns2 v0.23.0 h1:lpkikaZ995GIcKk6AFsYzHyezCrsrfEDvUWcWkEGErY=
 github.com/sideshow/apns2 v0.23.0/go.mod h1:7Fceu+sL0XscxrfLSkAoH6UtvKefq3Kq1n4W3ayQZqE=
 github.com/sirupsen/logrus v1.7.0/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0=
+github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ=
+github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
 github.com/spaolacci/murmur3 v1.1.0 h1:7c1g84S4BPRrfL5Xrdp6fOJ206sU9y293DDHaoy0bLI=
 github.com/spaolacci/murmur3 v1.1.0/go.mod h1:JwIasOWyU6f++ZhiEuf87xNszmSA2myDM2Kzu9HwQUA=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
@@ -131,6 +133,7 @@ golang.org/x/sys v0.0.0-20210510120138-977fb7262007/go.mod h1:oPkhp1MJrh7nUepCBc
 golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20211216021012-1d35b9e2eb4e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20220627191245-f75cf1eec38b/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.19.0 h1:q5f1RH2jigJ1MoAWp2KTp3gm5zAGFUTarQZ5U386+4o=
 golang.org/x/sys v0.19.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
 golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=

toot-relay.go

@@ -5,10 +5,8 @@ import (
 	"crypto/x509"
 	"encoding/base64"
 	"encoding/binary"
-	"errors"
 	"flag"
 	"fmt"
-	"log"
 	"net/http"
 	"os"
 	"strconv"
@@ -18,6 +16,7 @@ import (
 	"github.com/sideshow/apns2"
 	"github.com/sideshow/apns2/certificate"
 	"github.com/sideshow/apns2/payload"
+	log "github.com/sirupsen/logrus"
 	"golang.org/x/net/http2"
 
 	httptrace "gopkg.in/DataDog/dd-trace-go.v1/contrib/net/http"
@@ -39,8 +38,8 @@ var (
 )
 
 func worker(workerId int) {
-	log.Printf("starting worker %d", workerId)
-	defer log.Printf("stopping worker %d", workerId)
+	log.Info(fmt.Sprintf("starting worker %d", workerId))
+	defer log.Info(fmt.Sprintf("stopping worker %d", workerId))
 
 	var client *apns2.Client
 
@@ -54,17 +53,26 @@ func worker(workerId int) {
 		res, err := client.Push(msg.notification)
 
 		if err != nil {
-			log.Println("Push error:", err)
+			log.Error(fmt.Sprintf("Push error: %s", err))
 			continue
 		}
 
 		if res.Sent() {
-			log.Printf("Sent notification to %s -> %v %v %v", msg.notification.DeviceToken, res.StatusCode, res.ApnsID, res.Reason)
-			log.Println("Expiration:", msg.notification.Expiration)
-			log.Println("Priority:", msg.notification.Priority)
-			log.Println("CollapseID:", msg.notification.CollapseID)
+			log.WithFields(log.Fields{
+				"status-code":  res.StatusCode,
+				"apns-id":      res.ApnsID,
+				"reason":       res.Reason,
+				"device-token": msg.notification.DeviceToken,
+				"expiration":   msg.notification.Expiration,
+				"priority":     msg.notification.Priority,
+				"collapse-id":  msg.notification.CollapseID,
+			}).Info(fmt.Sprintf("Sent notification (%v)", res.StatusCode))
 		} else {
-			log.Printf("Failed to send: %v %v %v\n", res.StatusCode, res.ApnsID, res.Reason)
+			log.WithFields(log.Fields{
+				"status-code": res.StatusCode,
+				"apns-id":     res.ApnsID,
+				"reason":      res.Reason,
+			}).Error(fmt.Sprintf("Failed to send notification (%v)", res.StatusCode))
 		}
 	}
 }
@@ -98,27 +106,27 @@ func main() {
 	if caPEM, err := os.ReadFile(caFile); err == nil {
 		rootCAs = x509.NewCertPool()
 		if ok := rootCAs.AppendCertsFromPEM(caPEM); !ok {
-			log.Fatalf("CA file %s specified but no CA certificates could be loaded\n", caFile)
+			log.Fatal(fmt.Sprintf("CA file %s specified but no CA certificates could be loaded\n", caFile))
 		}
 	}
 
 	if p12base64 != "" {
 		bytes, err := base64.StdEncoding.DecodeString(p12base64)
 		if err != nil {
-			log.Fatal("Base64 decoding error: ", err)
+			log.Fatal(fmt.Sprintf("Base64 decoding error: %s", err))
 		}
 
 		cert, err := certificate.FromP12Bytes(bytes, p12password)
 		if err != nil {
-			log.Fatal("Error parsing certificate: ", err)
+			log.Fatal(fmt.Sprintf("Error parsing certificate: %s", err))
 		}
 
 		developmentClient = apns2.NewClient(cert).Development()
 		productionClient = apns2.NewClient(cert).Production()
 	} else {
 		cert, err := certificate.FromP12File(p12file, p12password)
 		if err != nil {
-			log.Fatal("Error loading certificate file: ", err)
+			log.Fatal(fmt.Sprintf("Error loading certificate file: %s", err))
 		}
 
 		developmentClient = apns2.NewClient(cert).Development()
@@ -150,7 +158,7 @@ func handler(writer http.ResponseWriter, request *http.Request) {
 	if len(components) < 4 {
 		writer.WriteHeader(500)
 		fmt.Fprintln(writer, "Invalid URL path:", request.URL.Path)
-		log.Println("Invalid URL path:", request.URL.Path)
+		log.Error(fmt.Sprintf("Invalid URL path: %s", request.URL.Path))
 		return
 	}
 
@@ -178,7 +186,7 @@ func handler(writer http.ResponseWriter, request *http.Request) {
 		} else {
 			writer.WriteHeader(500)
 			fmt.Fprintln(writer, "Error retrieving public key:", err)
-			log.Println("Error retrieving public key:", err)
+			log.Error(fmt.Sprintf("Error retrieving public key: %s", err))
 			return
 		}
 
@@ -187,14 +195,14 @@ func handler(writer http.ResponseWriter, request *http.Request) {
 		} else {
 			writer.WriteHeader(500)
 			fmt.Fprintln(writer, "Error retrieving salt:", err)
-			log.Println("Error retrieving salt:", err)
+			log.Error(fmt.Sprintf("Error retrieving salt: %s", err))
 			return
 		}
 	//case "aes128gcm": // No further headers needed. However, not implemented on client side so return 415.
 	default:
 		writer.WriteHeader(415)
 		fmt.Fprintln(writer, "Unsupported Content-Encoding:", request.Header.Get("Content-Encoding"))
-		log.Println("Unsupported Content-Encoding:", request.Header.Get("Content-Encoding"))
+		log.Error(fmt.Sprintf("Unsupported Content-Encoding: %s", request.Header.Get("Content-Encoding")))
 		return
 	}
 
@@ -233,7 +241,7 @@ func encodedValue(header http.Header, name, key string) (string, error) {
 	keyValues := parseKeyValues(header.Get(name))
 	value, exists := keyValues[key]
 	if !exists {
-		return "", errors.New(fmt.Sprintf("Value %s not found in header %s", key, name))
+		return "", fmt.Errorf("value %s not found in header %s", key, name)
 	}
 
 	bytes, err := base64.RawURLEncoding.DecodeString(value)