Logs from some loggers are not synced/flushed

[amanbolat]

Issue: when i use zerolog or zap loggers 60% of time logs are not synced, so they are not displayed in CloudWatch.

Code of my handler:

var handlerInitialized = false
var chiAdapter *chiadapter.ChiLambda
var logger *zerolog.Logger

func Handler(req events.APIGatewayProxyRequest) (events.APIGatewayProxyResponse, error) {
	if !handlerInitialized {
		logger = zerolog.New(os.Stderr)
		logger.Info("cold_start")

		api := server.NewAPI(&logger)
		chiAdapter = chiadapter.New(api.Router())
		handlerInitialized = true
	}

	return chiAdapter.Proxy(req)
}

func main() {
	lambda.Start(Handler)
}

used: https://github.com/awslabs/aws-lambda-go-api-proxy

Half of logs that comes from http Handlers and middlewares are not shown.

I found that only standard logger and https://github.com/apex/log work correctly.
I already asked this question in many places, and tried to use zap's logger.Sync() to flush, but it doesn't help.

[tonyghita]

I'm finding the same behavior with https://github.com/uber-go/zap. Logs are non-deterministically picked up from stderr by the CloudWatch Logs agent.

zap opens stderr as a write-only file, in append, asynchronous I/O mode. I think Lambda has trouble picking up the async I/O. zerolog may be doing something similar.

In your example, you could add a os.Stderr.Sync() before exiting or after writing a line.

var handlerInitialized = false
var chiAdapter *chiadapter.ChiLambda
var logger *zerolog.Logger

func Handler(req events.APIGatewayProxyRequest) (events.APIGatewayProxyResponse, error) {
	if !handlerInitialized {
		logger = zerolog.New(os.Stderr)
		logger.Info("cold_start")

		api := server.NewAPI(&logger)
		chiAdapter = chiadapter.New(api.Router())
		handlerInitialized = true
	}

	return chiAdapter.Proxy(req)
}

func main() {
	lambda.Start(Handler)
        if err := os.Stderr.Sync(); err != nil {
            log.Println(err)
        } // force synchronous write to /dev/stderr before exiting
}

[amanbolat]

@tonyghita I will try to add os.Stderr.Sync() but i found that sometimes any code running after lambda.Start(Handler) will not work.

[tonyghita]

Ahh, good point. lambda.Start() won't return.

I created a hook using zap to sync os.Stderr after every log entry.

// flush() is a logger Hook for flushing the log file after every entry.
// This is more expensive than using the default asynchronous I/O, but
// necessary for Lambda to pick up each log line.
// Don't do this in performance-sensitive applications.
func flush(f *os.File) func(zapcore.Entry) error {
	return func(zapcore.Entry) error {
		if f != nil {
			_ = f.Sync()
		}
		return nil
	}
}

// New creates a new logger that writes to /dev/stderr and syncs after every log entry.
// The syncing is necessary because AWS Lambda does not handle asynchronous I/O well.
func New() (*Logger, error) {
	log, err := zap.NewProduction(zap.Hooks(flush(os.Stderr)))
	if err != nil {
		return nil, err
	}

	return &Logger{log: log}, nil
}

I'm not familiar with zerolog, but maybe it provides a similar functionality?