From db044a88220f9c72dc257f79cf213ff6ddbd7b83 Mon Sep 17 00:00:00 2001 From: Jacob Hoffman-Andrews Date: Wed, 14 Sep 2022 11:25:02 -0700 Subject: [PATCH] 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 | 13 ++++--------- log/log.go | 21 +++++++++++++-------- log/log_test.go | 4 ++-- test/config-next/akamai-purger.json | 3 ++- test/config-next/bad-key-revoker.json | 3 ++- test/config-next/ca-a.json | 3 ++- test/config-next/ca-b.json | 3 ++- test/config-next/crl-storer.json | 3 ++- test/config-next/crl-updater.json | 4 +++- test/config-next/expiration-mailer.json | 3 ++- test/config-next/log-validator.json | 3 ++- test/config-next/nonce.json | 3 ++- test/config-next/ocsp-responder.json | 3 ++- test/config-next/ocsp-updater.json | 3 ++- test/config-next/publisher.json | 3 ++- test/config-next/ra.json | 3 ++- test/config-next/sa.json | 3 ++- test/config-next/va-remote-a.json | 3 ++- test/config-next/va-remote-b.json | 3 ++- test/config-next/va.json | 3 ++- test/config-next/wfe2.json | 3 ++- test/config/akamai-purger.json | 3 ++- test/config/bad-key-revoker.json | 3 ++- test/config/ca-a.json | 3 ++- test/config/ca-b.json | 3 ++- test/config/crl-storer.json | 3 ++- test/config/crl-updater.json | 4 +++- test/config/expiration-mailer.json | 3 ++- test/config/log-validator.json | 3 ++- test/config/nonce.json | 3 ++- test/config/ocsp-responder.json | 3 ++- test/config/ocsp-updater.json | 3 ++- test/config/publisher.json | 3 ++- test/config/ra.json | 3 ++- test/config/sa.json | 3 ++- test/config/va-remote-a.json | 3 ++- test/config/va-remote-b.json | 3 ++- test/config/va.json | 3 ++- test/config/wfe2.json | 3 ++- test/secrets/honeycomb_fake_password | 1 + 40 files changed, 94 insertions(+), 55 deletions(-) create mode 100644 test/secrets/honeycomb_fake_password diff --git a/cmd/config.go b/cmd/config.go index 52c62fd07..7dfc5d419 100644 --- a/cmd/config.go +++ b/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 diff --git a/log/log.go b/log/log.go index 66995412d..0354b74ba 100644 --- a/log/log.go +++ b/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)) } diff --git a/log/log_test.go b/log/log_test.go index 8f7e2347b..8b335eaae 100644 --- a/log/log_test.go +++ b/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) { diff --git a/test/config-next/akamai-purger.json b/test/config-next/akamai-purger.json index ac7cbf2ac..795dc1422 100644 --- a/test/config-next/akamai-purger.json +++ b/test/config-next/akamai-purger.json @@ -33,6 +33,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/bad-key-revoker.json b/test/config-next/bad-key-revoker.json index 3721547c8..5ffb2a9e5 100644 --- a/test/config-next/bad-key-revoker.json +++ b/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"} } } diff --git a/test/config-next/ca-a.json b/test/config-next/ca-a.json index 3064ed926..0451da0d1 100644 --- a/test/config-next/ca-a.json +++ b/test/config-next/ca-a.json @@ -136,6 +136,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/ca-b.json b/test/config-next/ca-b.json index 5d85acb09..ef95d02e2 100644 --- a/test/config-next/ca-b.json +++ b/test/config-next/ca-b.json @@ -136,6 +136,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/crl-storer.json b/test/config-next/crl-storer.json index 73116fb90..3495b7c17 100644 --- a/test/config-next/crl-storer.json +++ b/test/config-next/crl-storer.json @@ -31,6 +31,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/crl-updater.json b/test/config-next/crl-updater.json index 46aab0d08..5a62da84a 100644 --- a/test/config-next/crl-updater.json +++ b/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"} } } diff --git a/test/config-next/expiration-mailer.json b/test/config-next/expiration-mailer.json index 000f712e0..73afff166 100644 --- a/test/config-next/expiration-mailer.json +++ b/test/config-next/expiration-mailer.json @@ -39,6 +39,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/log-validator.json b/test/config-next/log-validator.json index 42221129d..90e929caa 100644 --- a/test/config-next/log-validator.json +++ b/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": [ diff --git a/test/config-next/nonce.json b/test/config-next/nonce.json index d74118313..6a31ec685 100644 --- a/test/config-next/nonce.json +++ b/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": { diff --git a/test/config-next/ocsp-responder.json b/test/config-next/ocsp-responder.json index d62ceab18..29888292b 100644 --- a/test/config-next/ocsp-responder.json +++ b/test/config-next/ocsp-responder.json @@ -62,6 +62,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/ocsp-updater.json b/test/config-next/ocsp-updater.json index bafeeefc6..97d676a8c 100644 --- a/test/config-next/ocsp-updater.json +++ b/test/config-next/ocsp-updater.json @@ -34,6 +34,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/publisher.json b/test/config-next/publisher.json index 1957ffd1d..2138ea507 100644 --- a/test/config-next/publisher.json +++ b/test/config-next/publisher.json @@ -45,6 +45,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/ra.json b/test/config-next/ra.json index 21042cfc0..c7f6688ef 100644 --- a/test/config-next/ra.json +++ b/test/config-next/ra.json @@ -107,6 +107,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/sa.json b/test/config-next/sa.json index 184a3bbe3..8fcceecec 100644 --- a/test/config-next/sa.json +++ b/test/config-next/sa.json @@ -69,6 +69,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/va-remote-a.json b/test/config-next/va-remote-a.json index 83dd4f467..0e1e184bf 100644 --- a/test/config-next/va-remote-a.json +++ b/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"} } } diff --git a/test/config-next/va-remote-b.json b/test/config-next/va-remote-b.json index 3434d72bb..5072bc675 100644 --- a/test/config-next/va-remote-b.json +++ b/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"} } } diff --git a/test/config-next/va.json b/test/config-next/va.json index 384943346..235072716 100644 --- a/test/config-next/va.json +++ b/test/config-next/va.json @@ -54,6 +54,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config-next/wfe2.json b/test/config-next/wfe2.json index ece6fd448..bea3ad0b7 100644 --- a/test/config-next/wfe2.json +++ b/test/config-next/wfe2.json @@ -82,6 +82,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/akamai-purger.json b/test/config/akamai-purger.json index a72edd285..3ba74b6fc 100644 --- a/test/config/akamai-purger.json +++ b/test/config/akamai-purger.json @@ -30,6 +30,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/bad-key-revoker.json b/test/config/bad-key-revoker.json index 58e8cc73f..34b8e4855 100644 --- a/test/config/bad-key-revoker.json +++ b/test/config/bad-key-revoker.json @@ -35,6 +35,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/ca-a.json b/test/config/ca-a.json index 1233a9c95..b6fc3bfff 100644 --- a/test/config/ca-a.json +++ b/test/config/ca-a.json @@ -130,6 +130,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/ca-b.json b/test/config/ca-b.json index 960d62f95..55319e92e 100644 --- a/test/config/ca-b.json +++ b/test/config/ca-b.json @@ -130,6 +130,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/crl-storer.json b/test/config/crl-storer.json index 7099fae43..e998df9b5 100644 --- a/test/config/crl-storer.json +++ b/test/config/crl-storer.json @@ -31,6 +31,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/crl-updater.json b/test/config/crl-updater.json index f6b70123f..61df13e50 100644 --- a/test/config/crl-updater.json +++ b/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"} } } diff --git a/test/config/expiration-mailer.json b/test/config/expiration-mailer.json index e325fe453..4a3368999 100644 --- a/test/config/expiration-mailer.json +++ b/test/config/expiration-mailer.json @@ -33,6 +33,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/log-validator.json b/test/config/log-validator.json index 42221129d..90e929caa 100644 --- a/test/config/log-validator.json +++ b/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": [ diff --git a/test/config/nonce.json b/test/config/nonce.json index 6f8798861..02e5e7e26 100644 --- a/test/config/nonce.json +++ b/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": { diff --git a/test/config/ocsp-responder.json b/test/config/ocsp-responder.json index 298636514..4a918aa4b 100644 --- a/test/config/ocsp-responder.json +++ b/test/config/ocsp-responder.json @@ -23,6 +23,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/ocsp-updater.json b/test/config/ocsp-updater.json index 320f5e559..3dde6a690 100644 --- a/test/config/ocsp-updater.json +++ b/test/config/ocsp-updater.json @@ -34,6 +34,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/publisher.json b/test/config/publisher.json index a266141f1..5ebe14f79 100644 --- a/test/config/publisher.json +++ b/test/config/publisher.json @@ -45,6 +45,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/ra.json b/test/config/ra.json index 6f0baae91..bdaae13d3 100644 --- a/test/config/ra.json +++ b/test/config/ra.json @@ -135,6 +135,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/sa.json b/test/config/sa.json index 73ae6a029..34fd53a93 100644 --- a/test/config/sa.json +++ b/test/config/sa.json @@ -44,6 +44,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/config/va-remote-a.json b/test/config/va-remote-a.json index ce1d96260..2ab736121 100644 --- a/test/config/va-remote-a.json +++ b/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": { diff --git a/test/config/va-remote-b.json b/test/config/va-remote-b.json index 70bb4cdf5..a65768f65 100644 --- a/test/config/va-remote-b.json +++ b/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": { diff --git a/test/config/va.json b/test/config/va.json index 2ad37c1b8..3445755e7 100644 --- a/test/config/va.json +++ b/test/config/va.json @@ -50,7 +50,8 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} }, "common": { diff --git a/test/config/wfe2.json b/test/config/wfe2.json index d4bcc170a..38dcf1215 100644 --- a/test/config/wfe2.json +++ b/test/config/wfe2.json @@ -78,6 +78,7 @@ }, "beeline": { "mute": true, - "dataset": "Test" + "serviceName": "Test", + "writeKey": {"passwordFile": "test/secrets/honeycomb_fake_password"} } } diff --git a/test/secrets/honeycomb_fake_password b/test/secrets/honeycomb_fake_password new file mode 100644 index 000000000..d6459e005 --- /dev/null +++ b/test/secrets/honeycomb_fake_password @@ -0,0 +1 @@ +xxx