escape logging; set default debug level (#178)

* escaping

* errs

impl/internal/did/testdata_test.go

@@ -34,7 +34,7 @@ func getTestData(fileName string) ([]byte, error) {
 }
 
 // retrieveTestVectorAs retrieves a test vector from the testdata folder and unmarshals it into the given interface
-func retrieveTestVectorAs(t *testing.T, fileName string, output interface{}) {
+func retrieveTestVectorAs(t *testing.T, fileName string, output any) {
 	t.Helper()
 	testDataBytes, err := getTestData(fileName)
 	require.NoError(t, err)

impl/pkg/dht/logging.go

@@ -4,10 +4,12 @@ import (
 	"strings"
 
 	"github.com/anacrolix/log"
+	"github.com/goccy/go-json"
 	"github.com/sirupsen/logrus"
 )
 
 func init() {
+	log.Default.WithDefaultLevel(log.Debug)
 	log.Default.Handlers = []log.Handler{logrusHandler{}}
 }
 
@@ -16,17 +18,36 @@ type logrusHandler struct{}
 // Handle implements the log.Handler interface for logrus.
 // It intentionally downgrades the log level to reduce verbosity.
 func (logrusHandler) Handle(record log.Record) {
-	entry := logrus.WithFields(logrus.Fields{"names": record.Names})
+	entry := logrus.WithField("names", strings.Join(record.Names, "/"))
 	msg := strings.Replace(record.Msg.String(), "\n", "", -1)
 
+	// Check if the log message is a valid JSON string
+	var jsonMsg map[string]any
+	if err := json.Unmarshal([]byte(msg), &jsonMsg); err == nil {
+		// If the log message is a valid JSON string, escape backslashes and double quotes within the field values
+		for k, v := range jsonMsg {
+			if strVal, ok := v.(string); ok {
+				escaped := strings.Replace(strVal, "\\", "\\\\", -1)
+				escaped = strings.Replace(escaped, "\"", "\\\"", -1)
+				jsonMsg[k] = escaped
+			}
+		}
+		// Marshal the modified JSON message back to a string
+		escapedMsg, _ := json.Marshal(jsonMsg)
+		msg = string(escapedMsg)
+	} else {
+		// If the log message is not a valid JSON string, replace newline characters with empty strings
+		msg = strings.Replace(msg, "\n", "", -1)
+	}
+
 	switch record.Level {
 	case log.Debug:
-		entry.Debugf("%s\n", msg)
+		entry.Debug(msg)
 	case log.Info:
-		entry.Infof("%s\n", msg)
+		entry.Info(msg)
 	case log.Warning, log.Error:
-		entry.Warnf("%s\n", msg)
+		entry.Warn(msg)
 	default:
-		entry.Debugf("%s\n", msg)
+		entry.Debug(msg)
 	}
 }

impl/pkg/server/pkarr.go

@@ -3,8 +3,10 @@ package server
 import (
 	"crypto/ed25519"
 	"encoding/binary"
+	"fmt"
 	"io"
 	"net/http"
+	"strings"
 
 	"github.com/gin-gonic/gin"
 
@@ -56,6 +58,11 @@ func (r *PkarrRouter) GetRecord(c *gin.Context) {
 
 	resp, err := r.service.GetPkarr(c, *id)
 	if err != nil {
+		// TODO(gabe): provide a more maintainable way to handle custom errors
+		if strings.Contains("spam", err.Error()) {
+			LoggingRespondErrMsg(c, fmt.Sprintf("too many requests for bad key %s", *id), http.StatusTooManyRequests)
+			return
+		}
 		LoggingRespondErrWithMsg(c, err, "failed to get pkarr record", http.StatusInternalServerError)
 		return
 	}

impl/pkg/service/pkarr.go

@@ -6,13 +6,12 @@ import (
 	"sync/atomic"
 	"time"
 
-	"github.com/goccy/go-json"
-	"github.com/tv42/zbase32"
-
 	ssiutil "github.com/TBD54566975/ssi-sdk/util"
 	"github.com/allegro/bigcache/v3"
 	"github.com/anacrolix/torrent/bencode"
+	"github.com/goccy/go-json"
 	"github.com/sirupsen/logrus"
+	"github.com/tv42/zbase32"
 
 	"github.com/TBD54566975/did-dht-method/internal/util"
 
@@ -139,7 +138,7 @@ func (s *PkarrService) GetPkarr(ctx context.Context, id string) (*pkarr.Response
 
 	// if the key is in the badGetCache, return an error
 	if _, err := s.badGetCache.Get(id); err == nil {
-		return nil, ssiutil.LoggingCtxErrorMsgf(ctx, err, "key [%s] looked up too frequently, please wait a bit before trying again", id)
+		return nil, ssiutil.LoggingCtxErrorMsgf(ctx, err, "bad key [%s] rate limited to prevent spam", id)
 	}
 
 	// first do a cache lookup

impl/pkg/service/pkarr_test.go

@@ -132,7 +132,7 @@ func TestPkarrService(t *testing.T) {
 
 		// try it again to make sure the cache is working
 		got, err = svc.GetPkarr(context.Background(), "uqaj3fcr9db6jg6o9pjs53iuftyj45r46aubogfaceqjbo6pp9sy")
-		assert.ErrorContains(t, err, "looked up too frequently, please wait a bit before trying again")
+		assert.ErrorContains(t, err, "rate limited to prevent spam")
 		assert.Empty(t, got)
 	})
 

impl/pkg/storage/db/bolt/bolt.go

@@ -2,9 +2,10 @@ package bolt
 
 import (
 	"context"
-	"encoding/json"
 	"time"
 
+	"github.com/goccy/go-json"
+
 	"github.com/pkg/errors"
 	"github.com/sirupsen/logrus"
 	bolt "go.etcd.io/bbolt"