volatiletech / sqlboiler

Generate a Go ORM tailored to your database schema.
BSD 3-Clause "New" or "Revised" License
6.73k stars 544 forks source link

Adapting logging to zap logger #407

Closed mickeyreiss closed 5 years ago

mickeyreiss commented 5 years ago

Because DebugWriter is an io.Writer, it is difficult to adapt it to zap.Logger.

It would be useful if the generated code provided a boil.Logger interface with a default implementation that accepts an io.Writer.

A related issue, which would enable use of the logger in production, is that log line length is unlimited. This means that very big queries (e.g. large JSON blobs) cause problems.

cc/ #128

mickeyreiss commented 5 years ago

I think it would be reasonable to follow the pattern set by go-migrate:

// Logger is an interface so you can pass in your own
// logging implementation.
type Logger interface {

    // Printf is like fmt.Printf
    Printf(format string, v ...interface{})

    // Verbose should return true when verbose logging output is wanted
    Verbose() bool
}
aarondl commented 5 years ago

Hey @mickeyreiss. One note is that it should not be used in production as it leaks secrets into logs. It's truly meant as a development "what's going on" here kind of log.

Now you mention it should be an interface, but it already is one, io.Writer is just another interface that you can implement. I'm a fan of zap (mostly of their older version) and use it in this context sometimes, and it just takes a little wrapping, it's not difficult. Maybe you're referring to the part where you can't really use structured logging since the arguments are already concatenated into the string and so you can't make use of that paradigm?

As far as line length goes there is no problem. If you implement an io.Writer interface with a wrapper around a zap.Logger and you'd like to truncate the length of the messages or even split them up into multiple calls to zap.Logger.Info/Debug etc. you can do all of that in your implementation.

I'm currently not seeing an issue here. Perhaps you can elaborate on what's not possible or difficult with the io.Writer that's better accomplished by your suggested interface? I'll wait to hear some more detail from you.

mickeyreiss commented 5 years ago

One note is that it should not be used in production as it leaks secrets into logs. It's truly meant as a development "what's going on" here kind of log.

Noted. In this case, we are looking at development and staging environments.

If you implement an io.Writer interface with a wrapper around a zap.Logger and you'd like to truncate the length of the messages or even split them up into multiple calls to zap.Logger.Info/Debug etc. you can do all of that in your implementation.

The challenge we faced was writing an efficient and correct implementation for splitting log lines written by sqlboiler.

The generated code is clear—each log line calls fmt.Fprintln(boil.DebugWriter, ..., but our code is then responsible for buffering this output and splitting on newlines(?) (what if the message contains a newline character?), in order to map these log events to zapLogger.Info/.Debug calls.

A more "loggy" interface would make our code a bit simpler, and allow us to avoid maintaining this code. In my opinion, it would also follow an expected convention for ORMs (at least based on my experience with Active Record, jooq, SLF4J, etc.)

If it doesn't make sense to incorporate a logger adapter in sqlboiler, we'll end up implementing our own io.Writer as you suggested.

Thanks for your response, @aarondl!

aarondl commented 5 years ago

I'm definitely not closed to the idea. Just want to make sure it's actually going to solve a real problem.

Another note is that each fmt.Fprintln call should only generate one io.Writer.Write call (https://golang.org/src/fmt/print.go?s=7209:7272#L242). Which should mean the splitting that you need to do is the same splitting that you'd have to do with the interface you've proposed. One message = one call to Write. So if you're concerned that a single call to write will create a line that is too long, then I can't see how it improves that with the newly proposed interface.

Is one of the issues you have with the io.Writer the presence of a zap wrapper implementation instead of being able to use zap itself to fullfill the interface?

Sorry you have to explain this like I'm 5, we'll get to the heart of the problem soon :D

mickeyreiss commented 5 years ago

Thanks, @aarondl. I may have been overthinking it.

Based on your feedback I've simplified down to this:

package data

import (
    "github.com/go-errors/errors"
    "go.uber.org/zap"
)

const maxLogLen = 1024

type zapLogger struct {
    *zap.SugaredLogger
}

func (l *zapLogger) Write(p []byte) (n int, err error) {
    if len(p) > maxLogLen {
        l.Debugw(string(p[:maxLogLen]), "truncated", true)
        return maxLogLen, errors.New("log line too long")
    }
    l.Debug(string(p))
    return len(p), nil
}

This doesn't seem too bad. For some reason, I was trying to create a reader with io.Pipe and bufio.Scanner, rather than trying the simpler thing first.

aarondl commented 5 years ago

I wondered if that might be the case which is why I mentioned the 1-to-1 between Fprintln/Write :) I like io.Writer because you can easily throw a file at that, or even buffered file, or a network connection :p

It seems like you're okay with the end-result so I'll close this. Thanks for opening the discussion :)