Skip to content

Commit

Permalink
feat: use structured logging
Browse files Browse the repository at this point in the history
  • Loading branch information
@aymanbagabas
aymanbagabas committed Oct 26, 2023
1 parent f36ed53 commit 9a9cca7
Show file tree
Hide file tree
Showing 5 changed files with 51 additions and 56 deletions.
14 changes: 7 additions & 7 deletions cmd.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,7 @@ func ensureDirs(path string) error {
return nil
}

func run(r io.Reader, w io.Writer, args []string) error {
func run(r io.Reader, w io.Writer, args ...string) error {
if len(args) != 2 {
return fmt.Errorf("expected 2 arguments, got %d", len(args))
}
Expand All @@ -53,14 +53,14 @@ func run(r io.Reader, w io.Writer, args []string) error {
handler := transfer.NewPktline(r, w, logger)
for _, cap := range capabilities {
if err := handler.WritePacketText(cap); err != nil {
logger.Logf("error sending capability: %s: %v", cap, err)
logger.Log("error sending capability", "cap", cap, "err", err)
}
}
if err := handler.WriteFlush(); err != nil {
logger.Logf("error flushing capabilities: %v", err)
logger.Log("error flushing capabilities", "err", err)
}
now := time.Now()
logger.Logf("umask %o", umask)
logger.Log("umask", "umask", umask)
backend := local.New(lfsPath, umask, &now)
p := transfer.NewProcessor(handler, backend, logger)
defer logger.Log("done processing commands")
Expand Down Expand Up @@ -94,15 +94,15 @@ func Command(stdin io.Reader, stdout io.Writer, stderr io.Writer, args ...string
errc := make(chan error, 1)

setup(done)
logger.Logf("git-lfs-transfer %s", "v1")
logger.Log("git-lfs-transfer", "version", "v1")
defer logger.Log("git-lfs-transfer completed")
go func() {
errc <- run(stdin, stdout, args)
errc <- run(stdin, stdout, args...)
}()

select {
case s := <-done:
logger.Logf("signal %q received", s)
logger.Log("signal received", "signal", s)
case err := <-errc:
logger.Log("done running")
fmt.Fprintln(stderr, Usage())
Expand Down
13 changes: 6 additions & 7 deletions main.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,13 +12,12 @@ import (
type tracerxLogger struct{}

// Log logs the given arguments if Debug is true.
func (*tracerxLogger) Log(v ...interface{}) {
tracerx.Printf("%v", v...)
}

// Logf logs the given arguments if Debug is true.
func (*tracerxLogger) Logf(format string, v ...interface{}) {
tracerx.Printf(format, v...)
func (*tracerxLogger) Log(msg string, kv ...interface{}) {
format := msg
for i := 0; i < len(kv); i += 2 {
format += " %s=%v"
}
tracerx.Printf(format, kv...)
}

var logger = new(tracerxLogger)
Expand Down
9 changes: 3 additions & 6 deletions transfer/log.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,16 +2,13 @@ package transfer

// Logger is a logging interface.
type Logger interface {
Log(v ...interface{})
Logf(format string, v ...interface{})
// Log logs the given message and structured arguments.
Log(msg string, kv ...interface{})
}

type noopLogger struct{}

var _ Logger = (*noopLogger)(nil)

// Log implements Logger.
func (*noopLogger) Log(...interface{}) {}

// Logf implements Logger.
func (*noopLogger) Logf(string, ...interface{}) {}
func (*noopLogger) Log(string, ...interface{}) {}
26 changes: 13 additions & 13 deletions transfer/pktline.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -50,55 +50,55 @@ func NewPktline(r io.Reader, w io.Writer, logger Logger) *Pktline {

// SendError sends an error msg.
func (p *Pktline) SendError(status uint32, message string) error {
p.logger.Logf("sending error: %d %s", status, message)
p.logger.Log("sending error status", "code", status, "msg", message)
if err := p.WritePacketText(fmt.Sprintf("status %03d", status)); err != nil {
p.logger.Logf("error writing status: %s", err)
p.logger.Log("failed to write packet", "err", err)
}
if err := p.WriteDelim(); err != nil {
p.logger.Logf("error writing delim: %s", err)
p.logger.Log("failed to write delimiter", "err", err)
}
if err := p.WritePacketText(message); err != nil {
p.logger.Logf("error writing message: %s", err)
p.logger.Log("failed to write message", "err", err)
}
return p.WriteFlush()
}

// SendStatus sends a status message.
func (p *Pktline) SendStatus(status Status) error {
p.logger.Logf("sending status: %s", status)
p.logger.Log("sending status", "code", status)
if err := p.WritePacketText(fmt.Sprintf("status %03d", status.Code())); err != nil {
p.logger.Logf("error writing status: %s", err)
p.logger.Log("failed to write status", "err", err)
}
if args := status.Args(); len(args) > 0 {
for _, arg := range args {
if err := p.WritePacketText(arg); err != nil {
p.logger.Logf("error writing arg: %s", err)
p.logger.Log("failed to write argument", "arg", arg, "err", err)
}
}
}
if msgs := status.Messages(); len(msgs) > 0 {
if err := p.WriteDelim(); err != nil {
p.logger.Logf("error writing delim: %s", err)
p.logger.Log("failed to write delimiter", "err", err)
}
for _, msg := range msgs {
if err := p.WritePacketText(msg); err != nil {
p.logger.Logf("error writing msg: %s", err)
p.logger.Log("failed to write message", "err", err)
}
}
} else if r := status.Reader(); r != nil {
p.logger.Logf("sending reader")
p.logger.Log("sending reader")
// Close reader if it implements io.Closer.
if c, ok := r.(io.Closer); ok {
defer c.Close() // nolint: errcheck
}
if err := p.WriteDelim(); err != nil {
p.logger.Logf("error writing delim: %v", err)
p.logger.Log("failed to write delimiter", "err", err)
}
w := p.Writer()
if _, err := io.Copy(w, r); err != nil {
p.logger.Logf("error copying reader: %v", err)
p.logger.Log("failed to copy reader", "err", err)
}
defer p.logger.Logf("done copying")
defer p.logger.Log("done copying")
return w.Flush()
}
return p.WriteFlush()
Expand Down
45 changes: 22 additions & 23 deletions transfer/processor.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,7 @@ func NewProcessor(line *Pktline, backend Backend, logger Logger) *Processor {
func (p *Processor) Version() (Status, error) {
_, err := p.handler.ReadPacketListToFlush()
if err != nil {
p.logger.Logf("version error: %s", err)
p.logger.Log("invalid version", "err", err)
}
return NewSuccessStatus([]string{}), nil
}
Expand Down Expand Up @@ -64,8 +64,7 @@ func (p *Processor) ReadBatch(op string) ([]BatchItem, error) {
default:
return nil, fmt.Errorf("%w: %s", ErrNotAllowed, fmt.Sprintf("unsupported hash algorithm: %s", hashAlgo))
}
p.logger.Logf("data: %d %v", len(data), data)
p.logger.Logf("batch: %s args: %d %v data: %d %v", op, len(args), args, len(data), data)
p.logger.Log("read batch", "operation", op, "args-len", len(args), "args", args, "data-len", len(data), "data", data)
items := make([]BatchItem, 0)
for _, line := range data {
if line == "" {
Expand Down Expand Up @@ -95,12 +94,12 @@ func (p *Processor) ReadBatch(op string) ([]BatchItem, error) {
}
items = append(items, item)
}
p.logger.Logf("items %v", items)
p.logger.Log("batch items", "items", items)
its, err := p.backend.Batch(op, items, args)
if err != nil {
return nil, err
}
p.logger.Logf("batch items: %v", its)
p.logger.Log("batch items", "items", items)
return its, nil
}

Expand Down Expand Up @@ -249,12 +248,12 @@ func (p *Processor) Lock() (Status, error) {
for {
lock, err := lockBackend.Create(path, refname)
if errors.Is(err, ErrConflict) {
p.logger.Logf("lock conflict")
p.logger.Log("lock conflict")
lock, err = lockBackend.FromPath(path)
if err != nil {
p.logger.Logf("lock conflict, but no lock found")
p.logger.Log("lock conflict, but no lock found")
if retried {
p.logger.Logf("lock conflict, but no lock found, and retried")
p.logger.Log("lock conflict, but no lock found, and retried")
return nil, err
}
retried = true
Expand All @@ -263,10 +262,10 @@ func (p *Processor) Lock() (Status, error) {
return NewFailureStatusWithArgs(StatusConflict, "conflict", lock.AsArguments()...), nil
}
if err != nil {
p.logger.Logf("lock error: %v", err)
p.logger.Log("failed to create lock", "err", err)
return nil, err
}
p.logger.Logf("lock success: %v", lock)
p.logger.Log("lock success", "lock", lock)
return NewSuccessStatusWithCode(StatusCreated, lock.AsArguments()...), nil
}
// unreachable
Expand Down Expand Up @@ -325,7 +324,7 @@ func (p *Processor) ListLocks(useOwnerID bool) (Status, error) {
// skip nil locks
return nil
}
p.logger.Logf("adding lock %s %s", lock.Path(), lock.ID())
p.logger.Log("adding lock", "path", lock.Path(), "id", lock.ID())
locks = append(locks, lock)
return nil
})
Expand Down Expand Up @@ -393,21 +392,21 @@ func (p *Processor) ProcessCommands(op string) error {
if err != nil {
return err
}
p.logger.Logf("received packet: %s", pkt)
p.logger.Log("received packet", "packet", pkt)
if pkt == "" {
if err := p.handler.SendError(StatusBadRequest, "unknown command"); err != nil {
p.logger.Logf("error pktline sending error: %v", err)
p.logger.Log("failed to send pktline", "err", err)
}
continue
}
msgs := strings.Split(pkt, " ")
if len(msgs) < 1 {
if err := p.handler.SendError(StatusBadRequest, "no command provided"); err != nil {
p.logger.Logf("error pktline sending error: %v", err)
p.logger.Log("failed to send pktline", "err", err)
}
continue
}
p.logger.Logf("received command: %s %v", msgs[0], msgs[1:])
p.logger.Log("received command", "command", msgs[0], "messages", msgs[1:])
var status Status
switch msgs[0] {
case versionCommand:
Expand All @@ -419,10 +418,10 @@ func (p *Processor) ProcessCommands(op string) error {
case batchCommand:
switch op {
case UploadOperation:
p.logger.Logf("upload batch command received")
p.logger.Log("upload batch command received")
status, err = p.UploadBatch()
case DownloadOperation:
p.logger.Logf("download batch command received")
p.logger.Log("download batch command received")
status, err = p.DownloadBatch()
default:
err = p.handler.SendError(StatusBadRequest, "unknown operation")
Expand Down Expand Up @@ -454,7 +453,7 @@ func (p *Processor) ProcessCommands(op string) error {
case DownloadOperation:
status, err = p.ListLocks(false)
}
p.logger.Logf("list lock status: %v %v", status, err)
p.logger.Log("list lock command", "status", status, "err", err)
case unlockCommand:
if len(msgs) > 1 {
status, err = p.Unlock(msgs[1])
Expand All @@ -463,7 +462,7 @@ func (p *Processor) ProcessCommands(op string) error {
}
case quitCommand:
if err := p.handler.SendStatus(SuccessStatus()); err != nil {
p.logger.Logf("error pktline sending status: %v", err)
p.logger.Log("failed to send pktline", "err", err)
}
return nil
default:
Expand All @@ -476,18 +475,18 @@ func (p *Processor) ProcessCommands(op string) error {
errors.Is(err, ErrInvalidPacket),
errors.Is(err, ErrCorruptData):
if err := p.handler.SendError(StatusBadRequest, fmt.Errorf("error: %w", err).Error()); err != nil {
p.logger.Logf("error pktline sending error: %v", err)
p.logger.Log("failed to send pktline", "err", err)
}
default:
p.logger.Logf("error processing command: %v", err)
p.logger.Log("failed to process command", "err", err)
if err := p.handler.SendError(StatusInternalServerError, "internal error"); err != nil {
p.logger.Logf("error pktline sending error: %v", err)
p.logger.Log("failed to send pktline", "err", err)
}
}
}
if status != nil {
if err := p.handler.SendStatus(status); err != nil {
p.logger.Logf("error pktline sending status: %v", err)
p.logger.Log("failed to send pktline", "err", err)
}
}
p.logger.Log("processed command")
Expand Down

0 comments on commit 9a9cca7

Please sign in to comment.