updates and tests for 2.0.2

README.md

@@ -1,7 +1,7 @@
 digilog
 ========
 
-Small wrapper around the built in Go "fmt" class to add logging levels.
+Simple Go event logger that mimics the built in Go Logger. Events can be recorded with prepopulated tags and metadata, or formatted at the time they are written. This package is meant to be extremely basic but offer some handy functionality for event logging, particularly for consumption by Splunk.
 
 ## Import
 
@@ -25,7 +25,9 @@ In your own application, logs can be written as such:
 ```
 log := digilog.New()
 log.Info("my_event_name", "othervar=123", "yetothervar=234")
-log.Infof("event_id=my_event_name %s %s", "othervar=123", "yetothervar=234")
+// outputs 2020-01-29T14:01:51-07:00 [INFO] event_id=my_event_name othervar=123 yetothervar=234
+log.Infof("my_event_name", "othervar=%s yetothervar=%s", "123", "234")
+// outputs 2020-01-29T14:01:51-07:00 [INFO] event_id=my_event_name othervar=123 yetothervar=234
 ```
 
 To override the writer:
@@ -34,10 +36,30 @@ To override the writer:
 log := digilog.New()
 log.SetOutput(&digilog.BuffOut{Out: fileWriter, Err: errFileWriter})
 log.Info("my_event_name", "othervar=123", "yetothervar=234")
+// outputs 2020-01-29T14:01:51-07:00 [INFO] event_id=my_event_name othervar=123 yetothervar=234 to fileWriter
+```
+
+To prepopulate tags or metadata (tags are permanent fixtures on every future log, metadata is ephemeral data that is flushed once it has been logged):
+
+```
+log := digilog.New()
+log.AddTags(map[string]interface{}{
+    "tag": "value",
+})
+log.AddTag("tag2", "value")
+log.AddMeta("meta_tag", "meta_value")
+log.Info("my_event_name")
+// outputs 2020-01-29T14:01:51-07:00 [INFO] event_id=my_event_name tag="value" tag2="value" meta_tag="meta_value"
+
+log.Info("my_event_name")
+// outputs 2020-01-29T14:01:51-07:00 [INFO] event_id=my_event_name tag="value" tag2="value"
+
 ```
 
 ## Version History
 
+2.0.2: Fixing bugs in the 2.0.0 release, adding more examples, and updating the README to be more accurate to how the library actually works.
+
 2.0.0: Mimic golang standard logger package using a Log struct and an output buffer. Is *not* a drop in replacement for Go Logger.
 
 1.2.0: Standardized funcs to mimic go's standard. If using Sprintf formatting, use the `f` suffixed method (Debugf, Infof, etc). Otherwise use the old methods

digilog.go

@@ -36,32 +36,60 @@ func init() {
 func New() *Log {
 
 	return &Log{
-		meta: make(map[string]interface{}),
-		out:  &BuffOut{Out: os.Stdout, Err: os.Stderr},
+		tags:   make(map[string]interface{}),
+		meta:   make(map[string]interface{}),
+		out:    &BuffOut{Out: os.Stdout, Err: os.Stderr},
+		caller: false,
 	}
 }
 
 // Log contains loggers for info and error logging as well as the data to be printed in said logs
 type Log struct {
-	meta map[string]interface{}
-	out  *BuffOut
+	tags   map[string]interface{}
+	meta   map[string]interface{}
+	out    *BuffOut
+	caller bool
 }
 
 // SetOutput changes the output buffer per log
 func (l *Log) SetOutput(o *BuffOut) {
 	l.out = o
 }
 
+// LogCaller logs the calling location (file and line)
+func (l *Log) LogCaller() {
+	l.caller = true
+}
+
 // Out return the writer for the Output buffer in the log
 func (l *Log) Out() io.Writer {
 	return l.out.Out
 }
 
-// AddTag adds metadata to a Log
+// AddTag adds permanent tags for each log entry
 func (l *Log) AddTag(key string, v interface{}) {
+	l.tags[key] = v
+}
+
+// AddTags appends a slice of permanent tags for each log entry
+func (l *Log) AddTags(m map[string]interface{}) {
+	for k, v := range m {
+		l.tags[k] = v
+	}
+}
+
+// AddMeta adds temporary metadata for the next log entry
+func (l *Log) AddMeta(key string, v interface{}) {
 	l.meta[key] = v
 }
 
+// AddMetas appends a slice of temporary metadata for the next log entry
+func (l *Log) AddMetas(m map[string]interface{}) {
+	for k, v := range m {
+		l.meta[k] = v
+	}
+}
+
 // AddDuration adds time.Duration to the log metadata
 func (l *Log) AddDuration(start time.Time) {
 	l.AddTag("duration", fmt.Sprintf("%s", time.Since(start)))
@@ -144,16 +172,25 @@ func (l *Log) prepareLog(event string, args ...interface{}) string {
 
 	logStr := fmt.Sprintf("event_id=%s ", event)
 
-	callStr, err := getCaller()
-	if err != nil {
-		fmt.Println("error getting caller information", err)
-		callStr = ""
+	callStr := ""
+	var err error
+	if l.caller {
+		callStr, err = getCaller()
+		if err != nil {
+			callStr = ""
+		}
 	}
 
 	logStr = fmt.Sprintf("%s%s", callStr, logStr)
 
+	for key, val := range l.tags {
+		strVal := fmt.Sprintf("%+v", val)
+		strVal = strings.ReplaceAll(strVal, `"`, "\\\"") // escape double quotes inside strings
+		logStr += fmt.Sprintf("%s=%q ", key, strVal)
+	}
+
 	for key, val := range l.meta {
-		strVal := fmt.Sprintf("%v", val)
+		strVal := fmt.Sprintf("%+v", val)
 		strVal = strings.ReplaceAll(strVal, `"`, "\\\"") // escape double quotes inside strings
 		logStr += fmt.Sprintf("%s=%q ", key, strVal)
 	}

digilog_test.go

@@ -10,6 +10,7 @@ import (
 )
 
 var testBuff *bytes.Buffer
+var Out *BuffOut
 
 func init() {
 	testBuff = &bytes.Buffer{}
@@ -28,6 +29,76 @@ func TestDebug(t *testing.T) {
 	assert.True(strings.Contains(testBuff.String(), "DEBUG"))
 	assert.True(strings.HasSuffix(testBuff.String(), "event_id=test_event salutation='hello world'\n"), "failed asserting that %s ends with %s", testBuff.String(), "event_id=test_event salutation='hello world'\n")
 }
+
+func TestDebug_AddTagStructAndMap(t *testing.T) {
+	type TestStruct struct {
+		One   string
+		Two   int
+		Three bool
+	}
+
+	s := TestStruct{
+		One:   "one",
+		Two:   2,
+		Three: true,
+	}
+
+	m := map[string]interface{}{
+		"Four": "Four",
+		"Five": 5,
+		"Six":  false,
+	}
+	testBuff.Reset()
+	assert := assert.New(t)
+
+	LogLevel = "DEBUG"
+	l := New()
+	l.SetOutput(Out)
+	l.AddTag("test_struct", s)
+	l.AddTag("test_map", m)
+	l.AddMeta("meta_string", "salutations")
+	l.AddMeta("meta_bool", true)
+
+	// Test that Tags and Meta are added in an expected format
+	l.Debug("test_event", "salutation='", "hello world", "'")
+	assert.True(strings.Contains(testBuff.String(), "DEBUG"))
+	e := "event_id=test_event test_struct=\"{One:one Two:2 Three:true}\" test_map=\"map[Five:5 Four:Four Six:false]\" meta_string=\"salutations\" meta_bool=\"true\" salutation='hello world'\n"
+	assert.True(strings.HasSuffix(testBuff.String(), e), "failed asserting that %s ends with %s", testBuff.String(), e)
+
+	// Test that meta is removed after the log is written
+	testBuff.Reset()
+	l.Debug("test_event", "salutation='", "hello world", "'")
+	e = "event_id=test_event test_struct=\"{One:one Two:2 Three:true}\" test_map=\"map[Five:5 Four:Four Six:false]\" salutation='hello world'\n"
+	assert.True(strings.HasSuffix(testBuff.String(), e), "failed asserting that %s ends with %s", testBuff.String(), e)
+}
+
+func TestDebug_AddTagsMetas(t *testing.T) {
+	testBuff.Reset()
+	assert := assert.New(t)
+
+	LogLevel = "DEBUG"
+	l := New()
+	l.SetOutput(Out)
+
+	l.AddTags(map[string]interface{}{
+		"salutation": "hello world",
+	})
+	l.AddMetas(map[string]interface{}{
+		"next_salutation": "goodbye world",
+	})
+
+	l.Debug("test_event")
+	assert.True(strings.Contains(testBuff.String(), "DEBUG"))
+	e := "event_id=test_event salutation=\"hello world\" next_salutation=\"goodbye world\" \n"
+	assert.True(strings.HasSuffix(testBuff.String(), e), "failed asserting that %s ends with %s", testBuff.String(), e)
+
+	testBuff.Reset()
+	l.Debug("test_event")
+	assert.True(strings.Contains(testBuff.String(), "DEBUG"))
+	e = "event_id=test_event salutation=\"hello world\" \n"
+	assert.True(strings.HasSuffix(testBuff.String(), e), "failed asserting that %s ends with %s", testBuff.String(), e)
+}
+
 func TestDebugf(t *testing.T) {
 	testBuff.Reset()
 	assert := assert.New(t)