Fix a few typos / clarify. (#169)

When pushing an object to the logger, and this object was the first
field added. Zerolog was outputting an invalid json blob, issuing an
extra comma before the object. This patch ensure that JSON is still valid
even if an object is pushed first to the logger.

Fixes #152

.travis.yml

@@ -4,6 +4,8 @@ go:
 - "1.8"
 - "1.9"
 - "1.10"
+- "1.11"
+- "1.12"
 - "master"
 matrix:
   allow_failures:

README.md

@@ -53,7 +53,7 @@ func main() {
     // UNIX Time is faster and smaller than most timestamps
     // If you set zerolog.TimeFieldFormat to an empty string,
     // logs will write with UNIX time
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Print("hello world")
 }
@@ -76,15 +76,20 @@ import (
 )
 
 func main() {
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Debug().
         Str("Scale", "833 cents").
         Float64("Interval", 833.09).
         Msg("Fibonacci is everywhere")
+    
+    log.Debug().
+        Str("Name", "Tom").
+        Send()
 }
 
-// Output: {"time":1524104936,"level":"debug","Scale":"833 cents","Interval":833.09,"message":"Fibonacci is everywhere"}
+// Output: {"level":"debug","Scale":"833 cents","Interval":833.09,"time":1562212768,"message":"Fibonacci is everywhere"}
+// Output: {"level":"debug","Name":"Tom","time":1562212768}
 ```
 
 > You'll note in the above example that when adding contextual fields, the fields are strongly typed. You can find the full list of supported fields [here](#standard-types)
@@ -102,7 +107,7 @@ import (
 )
 
 func main() {
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Info().Msg("hello world")
 }
@@ -138,7 +143,7 @@ import (
 )
 
 func main() {
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
     debug := flag.Bool("debug", false, "sets log level to debug")
 
     flag.Parse()
@@ -189,7 +194,7 @@ import (
 )
 
 func main() {
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Log().
         Str("foo", "bar").
@@ -215,7 +220,7 @@ func main() {
     err := errors.New("A repo man spends his life getting into tense situations")
     service := "myservice"
 
-    zerolog.TimeFieldFormat = ""
+    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
 
     log.Fatal().
         Err(err).
@@ -474,9 +479,8 @@ Some settings can be changed and will by applied to all loggers:
 * `zerolog.LevelFieldName`: Can be set to customize level field name.
 * `zerolog.MessageFieldName`: Can be set to customize message field name.
 * `zerolog.ErrorFieldName`: Can be set to customize `Err` field name.
-* `zerolog.TimeFieldFormat`: Can be set to customize `Time` field value formatting. If set with an empty string, times are formated as UNIX timestamp.
-    // DurationFieldUnit defines the unit for time.Duration type fields added
-    // using the Dur method.
+* `zerolog.TimeFieldFormat`: Can be set to customize `Time` field value formatting. If set with `zerolog.TimeFormatUnix` or `zerolog.TimeFormatUnixMs`, times are formated as UNIX timestamp.
+* DurationFieldUnit defines the unit for time.Duration type fields added using the Dur method.
 * `DurationFieldUnit`: Sets the unit of the fields added by `Dur` (default: `time.Millisecond`).
 * `DurationFieldInteger`: If set to true, `Dur` fields are formatted as integers instead of floats.
 * `ErrorHandler`: Called whenever zerolog fails to write an event on its output. If not set, an error is printed on the stderr. This handler must be thread safe and non-blocking.
@@ -578,7 +582,7 @@ Log a static string, without any context or `printf`-style templating:
 
 ## Caveats
 
-Note that zerolog does de-duplication fields. Using the same key multiple times creates multiple keys in final JSON:
+Note that zerolog does no de-duplication of fields. Using the same key multiple times creates multiple keys in final JSON:
 
 ```go
 logger := zerolog.New(os.Stderr).With().Timestamp().Logger()
@@ -588,4 +592,4 @@ logger.Info().
 // Output: {"level":"info","time":1494567715,"time":1494567715,"message":"dup"}
 ```
 
-However, it’s not a big deal as JSON accepts dup keys; the last one prevails.
+In this case, many consumers will take the last value, but this is not guaranteed; check yours if in doubt.

benchmark_test.go

@@ -234,7 +234,7 @@ func BenchmarkLogFieldType(b *testing.B) {
 
 func BenchmarkContextFieldType(b *testing.B) {
 	oldFormat := TimeFieldFormat
-	TimeFieldFormat = ""
+	TimeFieldFormat = TimeFormatUnix
 	defer func() { TimeFieldFormat = oldFormat }()
 	bools := []bool{true, false, true, false, true, false, true, false, true, false}
 	ints := []int{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}

console.go

@@ -13,11 +13,6 @@ import (
 	"time"
 )
 
-const (
-	colorBold = iota + 1
-	colorFaint
-)
-
 const (
 	colorBlack = iota + 30
 	colorRed
@@ -27,6 +22,9 @@ const (
 	colorMagenta
 	colorCyan
 	colorWhite
+
+	colorBold     = 1
+	colorDarkGray = 90
 )
 
 var (
@@ -297,9 +295,20 @@ func consoleDefaultFormatTimestamp(timeFormat string, noColor bool) Formatter {
 				t = ts.Format(timeFormat)
 			}
 		case json.Number:
-			t = tt.String()
+			i, err := tt.Int64()
+			if err != nil {
+				t = tt.String()
+			} else {
+				var sec, nsec int64 = i, 0
+				if TimeFieldFormat == TimeFormatUnixMs {
+					nsec = int64(time.Duration(i) * time.Millisecond)
+					sec = 0
+				}
+				ts := time.Unix(sec, nsec).UTC()
+				t = ts.Format(timeFormat)
+			}
 		}
-		return colorize(t, colorFaint, noColor)
+		return colorize(t, colorDarkGray, noColor)
 	}
 }
 
@@ -324,7 +333,11 @@ func consoleDefaultFormatLevel(noColor bool) Formatter {
 				l = colorize("???", colorBold, noColor)
 			}
 		} else {
-			l = strings.ToUpper(fmt.Sprintf("%s", i))[0:3]
+			if i == nil {
+				l = colorize("???", colorBold, noColor)
+			} else {
+				l = strings.ToUpper(fmt.Sprintf("%s", i))[0:3]
+			}
 		}
 		return l
 	}
@@ -342,19 +355,22 @@ func consoleDefaultFormatCaller(noColor bool) Formatter {
 				c = strings.TrimPrefix(c, cwd)
 				c = strings.TrimPrefix(c, "/")
 			}
-			c = colorize(c, colorBold, noColor) + colorize(" >", colorFaint, noColor)
+			c = colorize(c, colorBold, noColor) + colorize(" >", colorCyan, noColor)
 		}
 		return c
 	}
 }
 
 func consoleDefaultFormatMessage(i interface{}) string {
+	if i == nil {
+		return ""
+	}
 	return fmt.Sprintf("%s", i)
 }
 
 func consoleDefaultFormatFieldName(noColor bool) Formatter {
 	return func(i interface{}) string {
-		return colorize(fmt.Sprintf("%s=", i), colorFaint, noColor)
+		return colorize(fmt.Sprintf("%s=", i), colorCyan, noColor)
 	}
 }
 

console_test.go

@@ -76,7 +76,7 @@ func TestConsoleWriter(t *testing.T) {
 		buf := &bytes.Buffer{}
 		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, PartsOrder: []string{"foo"}}
 
-		_, err := w.Write([]byte(`{"foo" : "DEFAULT"}`))
+		_, err := w.Write([]byte(`{"foo": "DEFAULT"}`))
 		if err != nil {
 			t.Errorf("Unexpected error when writing output: %s", err)
 		}
@@ -92,12 +92,12 @@ func TestConsoleWriter(t *testing.T) {
 		buf := &bytes.Buffer{}
 		w := zerolog.ConsoleWriter{Out: buf, NoColor: false}
 
-		_, err := w.Write([]byte(`{"level" : "warn", "message" : "Foobar"}`))
+		_, err := w.Write([]byte(`{"level": "warn", "message": "Foobar"}`))
 		if err != nil {
 			t.Errorf("Unexpected error when writing output: %s", err)
 		}
 
-		expectedOutput := "\x1b[2m<nil>\x1b[0m \x1b[31mWRN\x1b[0m Foobar\n"
+		expectedOutput := "\x1b[90m<nil>\x1b[0m \x1b[31mWRN\x1b[0m Foobar\n"
 		actualOutput := buf.String()
 		if actualOutput != expectedOutput {
 			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
@@ -109,7 +109,7 @@ func TestConsoleWriter(t *testing.T) {
 		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
 
 		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
-		_, err := w.Write([]byte(`{"time" : "` + d + `", "level" : "debug", "message" : "Foobar", "foo" : "bar"}`))
+		_, err := w.Write([]byte(`{"time": "` + d + `", "level": "debug", "message": "Foobar", "foo": "bar"}`))
 		if err != nil {
 			t.Errorf("Unexpected error when writing output: %s", err)
 		}
@@ -121,12 +121,104 @@ func TestConsoleWriter(t *testing.T) {
 		}
 	})
 
+	t.Run("Unix timestamp input format", func(t *testing.T) {
+		of := zerolog.TimeFieldFormat
+		defer func() {
+			zerolog.TimeFieldFormat = of
+		}()
+		zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
+
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, TimeFormat: time.StampMilli, NoColor: true}
+
+		_, err := w.Write([]byte(`{"time": 1234, "level": "debug", "message": "Foobar", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "Jan  1 00:20:34.000 DBG Foobar foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Unix timestamp ms input format", func(t *testing.T) {
+		of := zerolog.TimeFieldFormat
+		defer func() {
+			zerolog.TimeFieldFormat = of
+		}()
+		zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMs
+
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, TimeFormat: time.StampMilli, NoColor: true}
+
+		_, err := w.Write([]byte(`{"time": 1234567, "level": "debug", "message": "Foobar", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "Jan  1 00:20:34.567 DBG Foobar foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("No message field", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
+
+		_, err := w.Write([]byte(`{"level": "debug", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "<nil> DBG  foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("No level field", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
+
+		_, err := w.Write([]byte(`{"message": "Foobar", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "<nil> ??? Foobar foo=bar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
+	t.Run("Write colorized fields", func(t *testing.T) {
+		buf := &bytes.Buffer{}
+		w := zerolog.ConsoleWriter{Out: buf, NoColor: false}
+
+		_, err := w.Write([]byte(`{"level": "warn", "message": "Foobar", "foo": "bar"}`))
+		if err != nil {
+			t.Errorf("Unexpected error when writing output: %s", err)
+		}
+
+		expectedOutput := "\x1b[90m<nil>\x1b[0m \x1b[31mWRN\x1b[0m Foobar \x1b[36mfoo=\x1b[0mbar\n"
+		actualOutput := buf.String()
+		if actualOutput != expectedOutput {
+			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
+		}
+	})
+
 	t.Run("Write error field", func(t *testing.T) {
 		buf := &bytes.Buffer{}
 		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
 
 		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
-		evt := `{"time" : "` + d + `", "level" : "error", "message" : "Foobar", "aaa" : "bbb", "error" : "Error"}`
+		evt := `{"time": "` + d + `", "level": "error", "message": "Foobar", "aaa": "bbb", "error": "Error"}`
 		// t.Log(evt)
 
 		_, err := w.Write([]byte(evt))
@@ -151,7 +243,7 @@ func TestConsoleWriter(t *testing.T) {
 		}
 
 		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
-		evt := `{"time" : "` + d + `", "level" : "debug", "message" : "Foobar", "foo" : "bar", "caller" : "` + cwd + `/foo/bar.go"}`
+		evt := `{"time": "` + d + `", "level": "debug", "message": "Foobar", "foo": "bar", "caller": "` + cwd + `/foo/bar.go"}`
 		// t.Log(evt)
 
 		_, err = w.Write([]byte(evt))
@@ -170,7 +262,7 @@ func TestConsoleWriter(t *testing.T) {
 		buf := &bytes.Buffer{}
 		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
 
-		evt := `{"level" : "debug", "message" : "Foobar", "foo" : [1, 2, 3], "bar" : true}`
+		evt := `{"level": "debug", "message": "Foobar", "foo": [1, 2, 3], "bar": true}`
 		// t.Log(evt)
 
 		_, err := w.Write([]byte(evt))
@@ -192,7 +284,7 @@ func TestConsoleWriterConfiguration(t *testing.T) {
 		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, TimeFormat: time.RFC3339}
 
 		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
-		evt := `{"time" : "` + d + `", "level" : "info", "message" : "Foobar"}`
+		evt := `{"time": "` + d + `", "level": "info", "message": "Foobar"}`
 
 		_, err := w.Write([]byte(evt))
 		if err != nil {
@@ -210,7 +302,7 @@ func TestConsoleWriterConfiguration(t *testing.T) {
 		buf := &bytes.Buffer{}
 		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, PartsOrder: []string{"message", "level"}}
 
-		evt := `{"level" : "info", "message" : "Foobar"}`
+		evt := `{"level": "info", "message": "Foobar"}`
 		_, err := w.Write([]byte(evt))
 		if err != nil {
 			t.Errorf("Unexpected error when writing output: %s", err)
@@ -228,7 +320,7 @@ func BenchmarkConsoleWriter(b *testing.B) {
 	b.ResetTimer()
 	b.ReportAllocs()
 
-	var msg = []byte(`{"level" : "info", "foo" : "bar", "message" : "HELLO", "time" : "1990-01-01"}`)
+	var msg = []byte(`{"level": "info", "foo": "bar", "message": "HELLO", "time": "1990-01-01"}`)
 
 	w := zerolog.ConsoleWriter{Out: ioutil.Discard, NoColor: false}
 

context.go

@@ -2,6 +2,7 @@ package zerolog
 
 import (
 	"io/ioutil"
+	"math"
 	"net"
 	"time"
 )
@@ -347,14 +348,31 @@ func (c Context) Interface(key string, i interface{}) Context {
 	return c
 }
 
-type callerHook struct{}
-
-func (ch callerHook) Run(e *Event, level Level, msg string) {
-	// Three extra frames to skip (added by hook infra).
-	e.caller(CallerSkipFrameCount + 3)
+type callerHook struct {
+	callerSkipFrameCount int
 }
 
-var ch = callerHook{}
+func newCallerHook(skipFrameCount int) callerHook {
+	return callerHook{callerSkipFrameCount: skipFrameCount}
+}
+
+func (ch callerHook) Run(e *Event, level Level, msg string) {
+	switch ch.callerSkipFrameCount {
+	case useGlobalSkipFrameCount:
+		// Extra frames to skip (added by hook infra).
+		e.caller(CallerSkipFrameCount + contextCallerSkipFrameCount)
+	default:
+		// Extra frames to skip (added by hook infra).
+		e.caller(ch.callerSkipFrameCount + contextCallerSkipFrameCount)
+	}
+}
+
+// useGlobalSkipFrameCount acts as a flag to informat callerHook.Run
+// to use the global CallerSkipFrameCount.
+const useGlobalSkipFrameCount = math.MinInt32
+
+// ch is the default caller hook using the global CallerSkipFrameCount.
+var ch = newCallerHook(useGlobalSkipFrameCount)
 
 // Caller adds the file:line of the caller with the zerolog.CallerFieldName key.
 func (c Context) Caller() Context {
@@ -362,6 +380,14 @@ func (c Context) Caller() Context {
 	return c
 }
 
+// CallerWithSkipFrameCount adds the file:line of the caller with the zerolog.CallerFieldName key.
+// The specified skipFrameCount int will override the global CallerSkipFrameCount for this context's respective logger.
+// If set to -1 the global CallerSkipFrameCount will be used.
+func (c Context) CallerWithSkipFrameCount(skipFrameCount int) Context {
+	c.l = c.l.Hook(newCallerHook(skipFrameCount))
+	return c
+}
+
 type stackTraceHook struct{}
 
 func (sh stackTraceHook) Run(e *Event, level Level, msg string) {

event.go

@@ -5,7 +5,6 @@ import (
 	"net"
 	"os"
 	"runtime"
-	"strconv"
 	"sync"
 	"time"
 )
@@ -106,10 +105,20 @@ func (e *Event) Msg(msg string) {
 	e.msg(msg)
 }
 
-// Msgf sends the event with formated msg added as the message field if not empty.
+// Send is equivalent to calling Msg("").
 //
-// NOTICE: once this methid is called, the *Event should be disposed.
-// Calling Msg twice can have unexpected result.
+// NOTICE: once this method is called, the *Event should be disposed.
+func (e *Event) Send() {
+	if e == nil {
+		return
+	}
+	e.msg("")
+}
+
+// Msgf sends the event with formatted msg added as the message field if not empty.
+//
+// NOTICE: once this method is called, the *Event should be disposed.
+// Calling Msgf twice can have unexpected result.
 func (e *Event) Msgf(format string, v ...interface{}) {
 	if e == nil {
 		return
@@ -118,13 +127,8 @@ func (e *Event) Msgf(format string, v ...interface{}) {
 }
 
 func (e *Event) msg(msg string) {
-	if len(e.ch) > 0 {
-		e.ch[0].Run(e, e.level, msg)
-		if len(e.ch) > 1 {
-			for _, hook := range e.ch[1:] {
-				hook.Run(e, e.level, msg)
-			}
-		}
+	for _, hook := range e.ch {
+		hook.Run(e, e.level, msg)
 	}
 	if msg != "" {
 		e.buf = enc.AppendString(enc.AppendKey(e.buf, MessageFieldName), msg)
@@ -673,7 +677,7 @@ func (e *Event) caller(skip int) *Event {
 	if !ok {
 		return e
 	}
-	e.buf = enc.AppendString(enc.AppendKey(e.buf, CallerFieldName), file+":"+strconv.Itoa(line))
+	e.buf = enc.AppendString(enc.AppendKey(e.buf, CallerFieldName), CallerMarshalFunc(file, line))
 	return e
 }
 

globals.go

@@ -1,8 +1,21 @@
 package zerolog
 
-import "time"
+import (
+	"strconv"
+	"time"
+)
 import "sync/atomic"
 
+const (
+	// TimeFormatUnix defines a time format that makes time fields to be
+	// serialized as Unix timestamp integers.
+	TimeFormatUnix = ""
+
+	// TimeFormatUnix defines a time format that makes time fields to be
+	// serialized as Unix timestamp integers in milliseconds.
+	TimeFormatUnixMs = "UNIXMS"
+)
+
 var (
 	// TimestampFieldName is the field name used for the timestamp field.
 	TimestampFieldName = "time"
@@ -10,6 +23,11 @@ var (
 	// LevelFieldName is the field name used for the level field.
 	LevelFieldName = "level"
 
+	// LevelFieldMarshalFunc allows customization of global level field marshaling
+	LevelFieldMarshalFunc = func(l Level) string {
+		return l.String()
+	}
+
 	// MessageFieldName is the field name used for the message field.
 	MessageFieldName = "message"
 
@@ -22,6 +40,11 @@ var (
 	// CallerSkipFrameCount is the number of stack frames to skip to find the caller.
 	CallerSkipFrameCount = 2
 
+	// CallerMarshalFunc allows customization of global caller marshaling
+	CallerMarshalFunc = func(file string, line int) string {
+		return file + ":" + strconv.Itoa(line)
+	}
+
 	// ErrorStackFieldName is the field name used for error stacks.
 	ErrorStackFieldName = "stack"
 
@@ -33,9 +56,9 @@ var (
 		return err
 	}
 
-	// TimeFieldFormat defines the time format of the Time field type.
-	// If set to an empty string, the time is formatted as an UNIX timestamp
-	// as integer.
+	// TimeFieldFormat defines the time format of the Time field type. If set to
+	// TimeFormatUnix or TimeFormatUnixMs, the time is formatted as an UNIX
+	// timestamp as integer.
 	TimeFieldFormat = time.RFC3339
 
 	// TimestampFunc defines the function called to generate a timestamp.

go.mod

@@ -1 +1,9 @@
 module github.com/rs/zerolog
+
+require (
+	github.com/coreos/go-systemd v0.0.0-20190321100706-95778dfbb74e
+	github.com/pkg/errors v0.8.1
+	github.com/rs/xid v1.2.1
+	github.com/zenazn/goji v0.9.0
+	golang.org/x/tools v0.0.0-20190425163242-31fd60d6bfdc
+)

go112.go

@@ -0,0 +1,7 @@
+// +build go1.12
+
+package zerolog
+
+// Since go 1.12, some auto generated init functions are hidden from
+// runtime.Caller.
+const contextCallerSkipFrameCount = 2

internal/cbor/types.go

@@ -24,9 +24,9 @@ func (Encoder) AppendEndMarker(dst []byte) []byte {
 
 // AppendObjectData takes an object in form of a byte array and appends to dst.
 func (Encoder) AppendObjectData(dst []byte, o []byte) []byte {
-        // BeginMarker is present in the dst, which
-        // should not be copied when appending to existing data.
-        return append(dst, o[1:]...)
+	// BeginMarker is present in the dst, which
+	// should not be copied when appending to existing data.
+	return append(dst, o[1:]...)
 }
 
 // AppendArrayStart adds markers to indicate the start of an array.

internal/json/time.go

@@ -5,11 +5,20 @@ import (
 	"time"
 )
 
+const (
+	// Import from zerolog/global.go
+	timeFormatUnix   = ""
+	timeFormatUnixMs = "UNIXMS"
+)
+
 // AppendTime formats the input time with the given format
 // and appends the encoded string to the input byte slice.
 func (e Encoder) AppendTime(dst []byte, t time.Time, format string) []byte {
-	if format == "" {
+	switch format {
+	case timeFormatUnix:
 		return e.AppendInt64(dst, t.Unix())
+	case timeFormatUnixMs:
+		return e.AppendInt64(dst, t.UnixNano()/1000000)
 	}
 	return append(t.AppendFormat(append(dst, '"'), format), '"')
 }
@@ -17,8 +26,11 @@ func (e Encoder) AppendTime(dst []byte, t time.Time, format string) []byte {
 // AppendTimes converts the input times with the given format
 // and appends the encoded string list to the input byte slice.
 func (Encoder) AppendTimes(dst []byte, vals []time.Time, format string) []byte {
-	if format == "" {
+	switch format {
+	case timeFormatUnix:
 		return appendUnixTimes(dst, vals)
+	case timeFormatUnixMs:
+		return appendUnixMsTimes(dst, vals)
 	}
 	if len(vals) == 0 {
 		return append(dst, '[', ']')
@@ -49,6 +61,21 @@ func appendUnixTimes(dst []byte, vals []time.Time) []byte {
 	return dst
 }
 
+func appendUnixMsTimes(dst []byte, vals []time.Time) []byte {
+	if len(vals) == 0 {
+		return append(dst, '[', ']')
+	}
+	dst = append(dst, '[')
+	dst = strconv.AppendInt(dst, vals[0].UnixNano()/1000000, 10)
+	if len(vals) > 1 {
+		for _, t := range vals[1:] {
+			dst = strconv.AppendInt(append(dst, ','), t.UnixNano()/1000000, 10)
+		}
+	}
+	dst = append(dst, ']')
+	return dst
+}
+
 // AppendDuration formats the input duration with the given unit & format
 // and appends the encoded string to the input byte slice.
 func (e Encoder) AppendDuration(dst []byte, d time.Duration, unit time.Duration, useInt bool) []byte {

internal/json/types.go

@@ -373,12 +373,17 @@ func (e Encoder) AppendInterface(dst []byte, i interface{}) []byte {
 // AppendObjectData takes in an object that is already in a byte array
 // and adds it to the dst.
 func (Encoder) AppendObjectData(dst []byte, o []byte) []byte {
-	// Two conditions we want to put a ',' between existing content and
-	// new content:
-	// 1. new content starts with '{' - which shd be dropped   OR
-	// 2. existing content has already other fields
+	// Three conditions apply here:
+	// 1. new content starts with '{' - which should be dropped   OR
+	// 2. new content starts with '{' - which should be replaced with ','
+	//    to separate with existing content OR
+	// 3. existing content has already other fields
 	if o[0] == '{' {
-		o[0] = ','
+		if len(dst) == 0 {
+			o = o[1:]
+		} else {
+			o[0] = ','
+		}
 	} else if len(dst) > 1 {
 		dst = append(dst, ',')
 	}

internal/json/types_test.go

@@ -165,3 +165,23 @@ func Test_appendMac(t *testing.T) {
 		})
 	}
 }
+
+func Test_appendObjectData(t *testing.T) {
+	tests := []struct {
+		dst  []byte
+		obj  []byte
+		want []byte
+	}{
+		{[]byte{}, []byte(`{"foo":"bar"}`), []byte(`"foo":"bar"}`)},
+		{[]byte(`{"qux":"quz"`), []byte(`{"foo":"bar"}`), []byte(`{"qux":"quz","foo":"bar"}`)},
+		{[]byte{}, []byte(`"foo":"bar"`), []byte(`"foo":"bar"`)},
+		{[]byte(`{"qux":"quz"`), []byte(`"foo":"bar"`), []byte(`{"qux":"quz","foo":"bar"`)},
+	}
+	for _, tt := range tests {
+		t.Run("ObjectData", func(t *testing.T) {
+			if got := enc.AppendObjectData(tt.dst, tt.obj); !reflect.DeepEqual(got, tt.want) {
+				t.Errorf("appendObjectData() = %s, want %s", got, tt.want)
+			}
+		})
+	}
+}

journald/journald.go

@@ -20,11 +20,12 @@ import (
 	"bytes"
 	"encoding/json"
 	"fmt"
+	"io"
+	"strings"
+
 	"github.com/coreos/go-systemd/journal"
 	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/internal/cbor"
-	"io"
-	"strings"
 )
 
 const defaultJournalDPrio = journal.PriNotice

log.go

@@ -94,8 +94,8 @@
 //            Msg("dup")
 //     // Output: {"level":"info","time":1494567715,"time":1494567715,"message":"dup"}
 //
-// However, it’s not a big deal though as JSON accepts dup keys,
-// the last one prevails.
+// In this case, many consumers will take the last value,
+// but this is not guaranteed; check yours if in doubt.
 package zerolog
 
 import (
@@ -152,19 +152,19 @@ func (l Level) String() string {
 // returns an error if the input string does not match known values.
 func ParseLevel(levelStr string) (Level, error) {
 	switch levelStr {
-	case DebugLevel.String():
+	case LevelFieldMarshalFunc(DebugLevel):
 		return DebugLevel, nil
-	case InfoLevel.String():
+	case LevelFieldMarshalFunc(InfoLevel):
 		return InfoLevel, nil
-	case WarnLevel.String():
+	case LevelFieldMarshalFunc(WarnLevel):
 		return WarnLevel, nil
-	case ErrorLevel.String():
+	case LevelFieldMarshalFunc(ErrorLevel):
 		return ErrorLevel, nil
-	case FatalLevel.String():
+	case LevelFieldMarshalFunc(FatalLevel):
 		return FatalLevel, nil
-	case PanicLevel.String():
+	case LevelFieldMarshalFunc(PanicLevel):
 		return PanicLevel, nil
-	case NoLevel.String():
+	case LevelFieldMarshalFunc(NoLevel):
 		return NoLevel, nil
 	}
 	return NoLevel, fmt.Errorf("Unknown Level String: '%s', defaulting to NoLevel", levelStr)
@@ -251,6 +251,11 @@ func (l Logger) Level(lvl Level) Logger {
 	return l
 }
 
+// GetLevel returns the current Level of l.
+func (l Logger) GetLevel() Level {
+	return l.level
+}
+
 // Sample returns a logger with the s sampler.
 func (l Logger) Sample(s Sampler) Logger {
 	l.sampler = s
@@ -291,6 +296,18 @@ func (l *Logger) Error() *Event {
 	return l.newEvent(ErrorLevel, nil)
 }
 
+// Err starts a new message with error level with err as a field if not nil or
+// with info level if err is nil.
+//
+// You must call Msg on the returned event in order to send the event.
+func (l *Logger) Err(err error) *Event {
+	if err != nil {
+		return l.Error().Err(err)
+	} else {
+		return l.Info()
+	}
+}
+
 // Fatal starts a new message with fatal level. The os.Exit(1) function
 // is called by the Msg method, which terminates the program immediately.
 //
@@ -380,7 +397,7 @@ func (l *Logger) newEvent(level Level, done func(string)) *Event {
 	e.done = done
 	e.ch = l.hooks
 	if level != NoLevel {
-		e.Str(LevelFieldName, level.String())
+		e.Str(LevelFieldName, LevelFieldMarshalFunc(level))
 	}
 	if l.context != nil && len(l.context) > 0 {
 		e.buf = enc.AppendObjectData(e.buf, l.context)

log_test.go

@@ -7,6 +7,8 @@ import (
 	"net"
 	"reflect"
 	"runtime"
+	"strconv"
+	"strings"
 	"testing"
 	"time"
 )
@@ -105,6 +107,20 @@ func TestWith(t *testing.T) {
 	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":"foo","bytes":"bar","hex":"12ef","json":{"some":"json"},"error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"float32":11.101,"float64":12.30303,"time":"0001-01-01T00:00:00Z","caller":"`+caller+`"}`+"\n"; got != want {
 		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
 	}
+
+	// Validate CallerWithSkipFrameCount.
+	out.Reset()
+	_, file, line, _ = runtime.Caller(0)
+	caller = fmt.Sprintf("%s:%d", file, line+5)
+	log = ctx.CallerWithSkipFrameCount(3).Logger()
+	func() {
+		log.Log().Msg("")
+	}()
+	// The above line is a little contrived, but the line above should be the line due
+	// to the extra frame skip.
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"string":"foo","bytes":"bar","hex":"12ef","json":{"some":"json"},"error":"some error","bool":true,"int":1,"int8":2,"int16":3,"int32":4,"int64":5,"uint":6,"uint8":7,"uint16":8,"uint32":9,"uint64":10,"float32":11.101,"float64":12.30303,"time":"0001-01-01T00:00:00Z","caller":"`+caller+`"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
 }
 
 func TestFieldsMap(t *testing.T) {
@@ -437,6 +453,24 @@ func TestLevel(t *testing.T) {
 	})
 }
 
+func TestGetLevel(t *testing.T) {
+	levels := []Level{
+		DebugLevel,
+		InfoLevel,
+		WarnLevel,
+		ErrorLevel,
+		FatalLevel,
+		PanicLevel,
+		NoLevel,
+		Disabled,
+	}
+	for _, level := range levels {
+		if got, want := New(nil).Level(level).GetLevel(), level; got != want {
+			t.Errorf("GetLevel() = %v, want: %v", got, want)
+		}
+	}
+}
+
 func TestSampling(t *testing.T) {
 	out := &bytes.Buffer{}
 	log := New(out).Sample(&BasicSampler{N: 2})
@@ -641,6 +675,75 @@ func TestErrorMarshalFunc(t *testing.T) {
 	}
 }
 
+func TestCallerMarshalFunc(t *testing.T) {
+	out := &bytes.Buffer{}
+	log := New(out)
+
+	// test default behaviour this is really brittle due to the line numbers
+	// actually mattering for validation
+	_, file, line, _ := runtime.Caller(0)
+	caller := fmt.Sprintf("%s:%d", file, line+2)
+	log.Log().Caller().Msg("msg")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"caller":"`+caller+`","message":"msg"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	// test custom behavior. In this case we'll take just the last directory
+	origCallerMarshalFunc := CallerMarshalFunc
+	defer func() { CallerMarshalFunc = origCallerMarshalFunc }()
+	CallerMarshalFunc = func(file string, line int) string {
+		parts := strings.Split(file, "/")
+		if len(parts) > 1 {
+			return strings.Join(parts[len(parts)-2:], "/") + ":" + strconv.Itoa(line)
+		} else {
+			return file + ":" + strconv.Itoa(line)
+		}
+	}
+	_, file, line, _ = runtime.Caller(0)
+	caller = CallerMarshalFunc(file, line+2)
+	log.Log().Caller().Msg("msg")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"caller":"`+caller+`","message":"msg"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+}
+
+func TestLevelFieldMarshalFunc(t *testing.T) {
+	origLevelFieldMarshalFunc := LevelFieldMarshalFunc
+	LevelFieldMarshalFunc = func(l Level) string {
+		return strings.ToUpper(l.String())
+	}
+	defer func() {
+		LevelFieldMarshalFunc = origLevelFieldMarshalFunc
+	}()
+	out := &bytes.Buffer{}
+	log := New(out)
+
+	log.Debug().Msg("test")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"DEBUG","message":"test"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	log.Info().Msg("test")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"INFO","message":"test"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	log.Warn().Msg("test")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"WARN","message":"test"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+
+	log.Error().Msg("test")
+	if got, want := decodeIfBinaryToString(out.Bytes()), `{"level":"ERROR","message":"test"}`+"\n"; got != want {
+		t.Errorf("invalid log output:\ngot:  %v\nwant: %v", got, want)
+	}
+	out.Reset()
+}
+
 type errWriter struct {
 	error
 }

not_go112.go

@@ -0,0 +1,5 @@
+// +build !go1.12
+
+package zerolog
+
+const contextCallerSkipFrameCount = 3

sampler.go

@@ -46,8 +46,12 @@ type BasicSampler struct {
 
 // Sample implements the Sampler interface.
 func (s *BasicSampler) Sample(lvl Level) bool {
+	n := s.N
+	if n == 1 {
+		return true
+	}
 	c := atomic.AddUint32(&s.counter, 1)
-	return c%s.N == s.N-1
+	return c%n == 1
 }
 
 // BurstSampler lets Burst events pass per Period then pass the decision to