log: fix spurious honeycomb warnings; improve stdout logger (#6364)

Honeycomb was emitting logs directly to stderr like this:

```
WARN: Missing API Key.
WARN: Dataset is ignored in favor of service name. Data will be sent to service name: boulder
```

Fix this by providing a fake API key and replacing "dataset" with "serviceName" in configs. Also add missing Honeycomb configs for crl-updater.

For stdout-only logger, include checksums and escape newlines.

cmd/config.go

@@ -9,7 +9,6 @@ import (
 	"hash/fnv"
 	"math"
 	"os"
-	"path"
 	"strings"
 	"time"
 
@@ -295,8 +294,10 @@ type BeelineConfig struct {
 	// directly in the JSON config for local development, or as a path to a
 	// separate file for production deployment.
 	WriteKey PasswordConfig
-	// Dataset is the event collection, e.g. Staging or Prod.
+	// Dataset deprecated.
 	Dataset string
+	// ServiceName is the event collection, e.g. Staging or Prod.
+	ServiceName string
 	// SampleRate is the (positive integer) denominator of the sample rate.
 	// Default: 1 (meaning all traces are sent). Set higher to send fewer traces.
 	SampleRate uint32
@@ -329,11 +330,6 @@ func makeSampler(rate uint32) func(fields map[string]interface{}) (bool, int) {
 // Load converts a BeelineConfig to a beeline.Config, loading the api WriteKey
 // and setting the ServiceName automatically.
 func (bc *BeelineConfig) Load() (beeline.Config, error) {
-	exec, err := os.Executable()
-	if err != nil {
-		return beeline.Config{}, fmt.Errorf("failed to get executable name: %w", err)
-	}
-
 	writekey, err := bc.WriteKey.Pass()
 	if err != nil {
 		return beeline.Config{}, fmt.Errorf("failed to get write key: %w", err)
@@ -341,8 +337,7 @@ func (bc *BeelineConfig) Load() (beeline.Config, error) {
 
 	return beeline.Config{
 		WriteKey:    writekey,
-		Dataset:     bc.Dataset,
-		ServiceName: path.Base(exec),
+		ServiceName: bc.ServiceName,
 		SamplerHook: makeSampler(bc.SampleRate),
 		Mute:        bc.Mute,
 	}, nil

log/log.go

@@ -178,6 +178,10 @@ func LogLineChecksum(line string) string {
 	return base64.RawURLEncoding.EncodeToString(buf)
 }
 
+func checkSummed(msg string) string {
+	return fmt.Sprintf("%s %s", LogLineChecksum(msg), msg)
+}
+
 // logAtLevel logs the provided message at the appropriate level, writing to
 // both stdout and the Logger
 func (w *bothWriter) logAtLevel(level syslog.Priority, msg string) {
@@ -186,7 +190,6 @@ func (w *bothWriter) logAtLevel(level syslog.Priority, msg string) {
 	// Since messages are delimited by newlines, we have to escape any internal or
 	// trailing newlines before generating the checksum or outputting the message.
 	msg = strings.Replace(msg, "\n", "\\n", -1)
-	msg = fmt.Sprintf("%s %s", LogLineChecksum(msg), msg)
 
 	w.Lock()
 	defer w.Unlock()
@@ -194,26 +197,26 @@ func (w *bothWriter) logAtLevel(level syslog.Priority, msg string) {
 	switch syslogAllowed := int(level) <= w.syslogLevel; level {
 	case syslog.LOG_ERR:
 		if syslogAllowed {
-			err = w.Err(msg)
+			err = w.Err(checkSummed(msg))
 		}
 	case syslog.LOG_WARNING:
 		if syslogAllowed {
-			err = w.Warning(msg)
+			err = w.Warning(checkSummed(msg))
 		}
 	case syslog.LOG_INFO:
 		if syslogAllowed {
-			err = w.Info(msg)
+			err = w.Info(checkSummed(msg))
 		}
 	case syslog.LOG_DEBUG:
 		if syslogAllowed {
-			err = w.Debug(msg)
+			err = w.Debug(checkSummed(msg))
 		}
 	default:
-		err = w.Err(fmt.Sprintf("%s (unknown logging level: %d)", msg, int(level)))
+		err = w.Err(fmt.Sprintf("%s (unknown logging level: %d)", checkSummed(msg), int(level)))
 	}
 
 	if err != nil {
-		fmt.Fprintf(os.Stderr, "Failed to write to syslog: %d %s (%s)\n", int(level), msg, err)
+		fmt.Fprintf(os.Stderr, "Failed to write to syslog: %d %s (%s)\n", int(level), checkSummed(msg), err)
 	}
 
 	w.stdoutWriter.logAtLevel(level, msg)
@@ -227,6 +230,8 @@ func (w *stdoutWriter) logAtLevel(level syslog.Priority, msg string) {
 			output = w.stderr
 		}
 
+		msg = strings.Replace(msg, "\n", "\\n", -1)
+
 		var color string
 		var reset string
 
@@ -249,7 +254,7 @@ func (w *stdoutWriter) logAtLevel(level syslog.Priority, msg string) {
 			w.prefix,
 			int(level),
 			path.Base(os.Args[0]),
-			msg,
+			checkSummed(msg),
 			reset); err != nil {
 			panic(fmt.Sprintf("failed to write to stdout: %v\n", err))
 		}

log/log_test.go

@@ -99,8 +99,8 @@ func TestStdoutLogger(t *testing.T) {
 	logger.Warning("Warning log")
 	logger.Info("Info log")
 
-	test.AssertEquals(t, stdout.String(), "1970-01-01T00:00:00+07:00  6 log.test Info log\n")
-	test.AssertEquals(t, stderr.String(), "1970-01-01T00:00:00+07:00  3 log.test [AUDIT] Error Audit\n1970-01-01T00:00:00+07:00  4 log.test Warning log\n")
+	test.AssertEquals(t, stdout.String(), "1970-01-01T00:00:00+07:00  6 log.test pcbo7wk Info log\n")
+	test.AssertEquals(t, stderr.String(), "1970-01-01T00:00:00+07:00  3 log.test 46_ghQg [AUDIT] Error Audit\n1970-01-01T00:00:00+07:00  4 log.test 97r2xAw Warning log\n")
 }
 
 func TestSyslogMethods(t *testing.T) {

test/config-next/akamai-purger.json

@@ -33,6 +33,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/bad-key-revoker.json

@@ -35,6 +35,7 @@
     },
     "beeline": {
         "mute": true,
-        "dataset": "Test"
+        "serviceName": "Test",
+        "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
     }
 }

test/config-next/ca-a.json

@@ -136,6 +136,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/ca-b.json

@@ -136,6 +136,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/crl-storer.json

@@ -31,6 +31,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/crl-updater.json

@@ -38,6 +38,8 @@
     "sysloglevel": -1
   },
   "beeline": {
-    "mute": true
+    "mute": true,
+    "serviceName": "Test",
+    "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/expiration-mailer.json

@@ -39,6 +39,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/log-validator.json

@@ -4,7 +4,8 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   },
   "debugAddr": ":8016",
   "files": [

test/config-next/nonce.json

@@ -8,7 +8,8 @@
         },
         "beeline": {
             "mute": true,
-            "dataset": "Test"
+            "serviceName": "Test",
+            "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
         },
         "debugAddr": ":8111",
         "grpc": {

test/config-next/ocsp-responder.json

@@ -62,6 +62,7 @@
  },
  "beeline": {
     "mute": true,
-    "dataset": "Test"
+    "serviceName": "Test",
+    "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
  }
 }

test/config-next/ocsp-updater.json

@@ -34,6 +34,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/publisher.json

@@ -45,6 +45,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/ra.json

@@ -107,6 +107,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/sa.json

@@ -69,6 +69,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/va-remote-a.json

@@ -41,6 +41,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/va-remote-b.json

@@ -41,6 +41,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/va.json

@@ -54,6 +54,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config-next/wfe2.json

@@ -82,6 +82,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/akamai-purger.json

@@ -30,6 +30,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/bad-key-revoker.json

@@ -35,6 +35,7 @@
     },
     "beeline": {
         "mute": true,
-        "dataset": "Test"
+        "serviceName": "Test",
+        "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
     }
 }

test/config/ca-a.json

@@ -130,6 +130,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/ca-b.json

@@ -130,6 +130,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/crl-storer.json

@@ -31,6 +31,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/crl-updater.json

@@ -35,6 +35,8 @@
     "sysloglevel": 6
   },
   "beeline": {
-    "mute": true
+    "mute": true,
+    "serviceName": "Test",
+    "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/expiration-mailer.json

@@ -33,6 +33,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/log-validator.json

@@ -4,7 +4,8 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   },
   "debugAddr": ":8016",
   "files": [

test/config/nonce.json

@@ -8,7 +8,8 @@
         },
         "beeline": {
             "mute": true,
-            "dataset": "Test"
+            "serviceName": "Test",
+            "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
         },
         "debugAddr": ":8111",
         "grpc": {

test/config/ocsp-responder.json

@@ -23,6 +23,7 @@
  },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
  }
 }

test/config/ocsp-updater.json

@@ -34,6 +34,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/publisher.json

@@ -45,6 +45,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/ra.json

@@ -135,6 +135,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/sa.json

@@ -44,6 +44,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/config/va-remote-a.json

@@ -42,7 +42,8 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   },
 
   "common": {

test/config/va-remote-b.json

@@ -42,7 +42,8 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   },
 
   "common": {

test/config/va.json

@@ -50,7 +50,8 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   },
 
   "common": {

test/config/wfe2.json

@@ -78,6 +78,7 @@
   },
   "beeline": {
       "mute": true,
-      "dataset": "Test"
+      "serviceName": "Test",
+      "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"}
   }
 }

test/secrets/honeycomb_fake_password

@@ -0,0 +1 @@
+xxx