zap: write error: sync /dev/stdout: invalid argument

Thanks for opensourcing this library!

Everything is fine during program execution, but when the application shuts down (due to an error) zap logs to stderr: write error: sync /dev/stdout: invalid argument

Output:

2017-02-20T17:25:14.708+0100	info	starting
2017-02-20T17:25:14.708+0100	info	publishing	{"port": 8080}
2017-02-20T17:45:54.522+0100	fatal	Error publishing the API	{"error": "listen tcp :8080: bind: address already in use"}
2017-02-20 17:25:14.708574765 +0100 CET write error: sync /dev/stdout: invalid argument
exit status 1

Relevant set-up code:

config.FileLoggingEnabled = false
config.EncodeLogsAsJson = false
...
encCfg := zapcore.EncoderConfig{
	TimeKey:        "@timestamp",
	LevelKey:       "level",
	NameKey:        "logger",
	CallerKey:      "caller",
	MessageKey:     "msg",
	StacktraceKey:  "stacktrace",
	EncodeLevel:    zapcore.LowercaseLevelEncoder,
	EncodeTime:     zapcore.ISO8601TimeEncoder,
	EncodeDuration: zapcore.NanosDurationEncoder,
}
...
func Configure() {
	writers := []zapcore.WriteSyncer{os.Stdout}
	if config.FileLoggingEnabled {
		writers = append(writers, newRollingFile(....))
	}
        GlobalLogger = newZapLogger(config.EncodeLogsAsJson, zapcore.NewMultiWriteSyncer(writers...))
}

func newZapLogger(encodeAsJSON bool, output zapcore.WriteSyncer) *zap.Logger {
	encoder := zapcore.NewConsoleEncoder(encoderCfg)
	if encodeAsJSON {
		encoder = zapcore.NewJSONEncoder(encoderCfg)
	}
	return zap.New(zapcore.NewCore(encoder, output, zap.NewAtomicLevel()))
}

About this issue

  • Original URL
  • State: closed
  • Created 7 years ago
  • Comments: 19 (13 by maintainers)

Commits related to this issue

Most upvoted comments

Thanks a lot @Ulexus, I forgot to come back to this

Thanks for the report @toefel18 and @Ulexus

The issue here is that fsync behaves differently on OSX and Linux. When doing a Fatal, zap calls Sync on os.Stdout, which ends up calling fsync.

The documentation for fsync specifies that EINVAL may be returned depending on the type of file passed in, but does not explicitly call out whether it will work for stdout. The Linux documentation says:

       EROFS, EINVAL
              fd is bound to a special file which does not support synchronization.

The OSX documentation is similar:

     [EINVAL]           fildes refers to a file type (e.g., a socket) that does not support this operation.

This simple example reproduces the issue with fsync behaving differently:

$ cat main.go
package main

import (
	"fmt"
	"os"
)

func main() {
	fmt.Println(os.Stdout.Sync())
}

OSX:

$ uname -a
Darwin prashant-[...] 15.6.0 Darwin Kernel Version 15.6.0: Mon Jan  9 23:07:29 PST 2017; root:xnu-3248.60.11.2.1~1/RELEASE_X86_64 x86_64


$ go run main.go
<nil>

Linux:

$ uname -a
Linux [..] 4.4.27 #1 SMP Sun Oct 23 18:20:55 UTC 2016 x86_64 GNU/Linux
$ go run main.go
fsync: invalid argument

@akshayjshah We have a couple of options here:

  1. Ignore all errors from Sync
  2. Specifically ignore EINVAL errors (harder to detect and more error prone)

This is trivial to reproduce:

package main

import "go.uber.org/zap"

func main() {
	log, err := zap.NewDevelopment()
	if err != nil {
		return
	}
	log.Fatal("dying now")
}
~/t/testzap $ go run main.go
2017-03-03T23:37:09.333-0500	FATAL	/home/scmccord/tmp/testzap/main.go:10	dying now
goroutine 1 [running]:
go.uber.org/zap.takeStacktrace(0xc420039800, 0x400, 0x400, 0x0, 0x0, 0xc420057c01)
	/home/scmccord/go/src/go.uber.org/zap/stacktrace.go:33 +0x64
go.uber.org/zap.Stack(0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/home/scmccord/go/src/go.uber.org/zap/field.go:205 +0x7a
go.uber.org/zap.(*Logger).check(0xc420014360, 0xc420010f05, 0x694c26, 0x9, 0x0)
	/home/scmccord/go/src/go.uber.org/zap/logger.go:268 +0x212
go.uber.org/zap.(*Logger).Fatal(0xc420014360, 0x694c26, 0x9, 0x0, 0x0, 0x0)
	/home/scmccord/go/src/go.uber.org/zap/logger.go:208 +0x44
main.main()
	/home/scmccord/tmp/testzap/main.go:10 +0x92

2017-03-03 23:37:09.33311913 -0500 EST write error: sync /dev/stderr: invalid argument
exit status 1

Sorry, what I meant to say is that ErrInvalid is not the error that’s returned in this case. As the comment on ErrInvalid says, the error is only returned when the *File methods are called with *File is nil. This snippet shows that the returned error is not os.ErrInvalid in the case when Sync fails:

package main

import (
	"fmt"
	"os"
)

func main() {
	err := os.Stdout.Sync()
	fmt.Println("err", err)
	fmt.Println("is ErrInvalid", err == os.ErrInvalid)
}

Output on Linux:

$ go run main.go
err fsync: invalid argument
is ErrInvalid false