tstor/src/host/vfs/log.go

package vfs

import (
	"context"
	"errors"
	"io/fs"
	"log/slog"
	"reflect"
	"time"

	"git.kmsign.ru/royalcat/tstor/pkg/rlog"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/trace"
)

type LogFS struct {
	fs  Filesystem
	log *slog.Logger

	timeout     time.Duration
	readTimeout time.Duration
}

func isLoggableError(err error) bool {
	return err != nil && !errors.Is(err, fs.ErrNotExist)
}

var _ Filesystem = (*LogFS)(nil)

func WrapLogFS(vfs Filesystem) *LogFS {
	return &LogFS{
		fs:          vfs,
		log:         rlog.ComponentLog("fs"),
		timeout:     time.Minute * 3,
		readTimeout: time.Minute,
	}
}

// ModTime implements Filesystem.
func (lfs *LogFS) ModTime() time.Time {
	return lfs.ModTime()
}

// Mode implements Filesystem.
func (lfs *LogFS) Mode() fs.FileMode {
	return lfs.Mode()
}

// Size implements Filesystem.
func (lfs *LogFS) Size() int64 {
	return lfs.Size()
}

// Sys implements Filesystem.
func (lfs *LogFS) Sys() any {
	return lfs.Sys()
}

func (fs *LogFS) FsName() string {
	return "logfs"
}

func (fs *LogFS) traceAttrs(add ...attribute.KeyValue) trace.SpanStartOption {
	return trace.WithAttributes(append([]attribute.KeyValue{
		attribute.String("fs", fs.FsName()),
	}, add...)...)
}

// Info implements Filesystem.
func (fs *LogFS) Info() (fs.FileInfo, error) {
	return fs.fs.Info()
}

// IsDir implements Filesystem.
func (fs *LogFS) IsDir() bool {
	return fs.fs.IsDir()
}

// Name implements Filesystem.
func (fs *LogFS) Name() string {
	return fs.fs.Name()
}

// Type implements Filesystem.
func (fs *LogFS) Type() fs.FileMode {
	return fs.fs.Type()
}

// Open implements Filesystem.
func (fs *LogFS) Open(ctx context.Context, filename string) (file File, err error) {
	ctx, cancel := context.WithTimeout(ctx, fs.timeout)
	defer cancel()
	ctx, span := tracer.Start(ctx, "Open",
		fs.traceAttrs(attribute.String("filename", filename)),
	)
	defer func() {
		if err != nil {
			span.RecordError(err)
		}
		span.End()
	}()

	file, err = fs.fs.Open(ctx, filename)
	if isLoggableError(err) {
		fs.log.With("filename", filename).Error("Failed to open file")
	}
	file = WrapLogFile(file, filename, fs.log, fs.readTimeout)
	return file, err
}

// ReadDir implements Filesystem.
func (fs *LogFS) ReadDir(ctx context.Context, path string) (entries []fs.DirEntry, err error) {
	ctx, cancel := context.WithTimeout(ctx, fs.timeout)
	defer cancel()
	ctx, span := tracer.Start(ctx, "ReadDir",
		fs.traceAttrs(attribute.String("path", path)),
	)
	defer func() {
		if err != nil {
			span.RecordError(err)
		}
		span.End()
	}()

	entries, err = fs.fs.ReadDir(ctx, path)
	if isLoggableError(err) {
		fs.log.ErrorContext(ctx, "Failed to read dir", "path", path, "error", err.Error(), "fs-type", reflect.TypeOf(fs.fs).Name())
	}
	return entries, err
}

// Stat implements Filesystem.
func (lfs *LogFS) Stat(ctx context.Context, filename string) (info fs.FileInfo, err error) {
	ctx, cancel := context.WithTimeout(ctx, lfs.timeout)
	defer cancel()
	ctx, span := tracer.Start(ctx, "Stat",
		lfs.traceAttrs(attribute.String("filename", filename)),
	)
	defer func() {
		if err != nil {
			span.RecordError(err)
		}
		span.End()
	}()

	info, err = lfs.fs.Stat(ctx, filename)
	if isLoggableError(err) {
		lfs.log.Error("Failed to stat", "filename", filename, "error", err)
	}
	return info, err
}

// Unlink implements Filesystem.
func (fs *LogFS) Unlink(ctx context.Context, filename string) (err error) {
	ctx, cancel := context.WithTimeout(ctx, fs.timeout)
	defer cancel()
	ctx, span := tracer.Start(ctx, "Unlink",
		fs.traceAttrs(attribute.String("filename", filename)),
	)
	defer func() {
		if err != nil {
			span.RecordError(err)
		}
		span.End()
	}()

	err = fs.fs.Unlink(ctx, filename)
	if isLoggableError(err) {
		fs.log.Error("Failed to stat", "filename", filename, "error", err)
	}
	return err
}

type LogFile struct {
	filename string
	f        File

	log     *slog.Logger
	timeout time.Duration
}

// Name implements File.
func (f *LogFile) Name() string {
	return f.f.Name()
}

// Type implements File.
func (f *LogFile) Type() fs.FileMode {
	return f.f.Type()
}

var _ File = (*LogFile)(nil)

func WrapLogFile(f File, filename string, log *slog.Logger, timeout time.Duration) *LogFile {
	return &LogFile{
		filename: filename,
		f:        f,
		log:      log.With("filename", filename),
		timeout:  timeout,
	}
}

// Close implements File.
func (f *LogFile) Close(ctx context.Context) (err error) {
	ctx, cancel := context.WithTimeout(ctx, f.timeout)
	defer cancel()
	ctx, span := tracer.Start(ctx, "Close",
		trace.WithAttributes(attribute.String("filename", f.filename)),
	)
	defer func() {
		if err != nil {
			span.RecordError(err)
		}
		span.End()
	}()

	err = f.f.Close(ctx)
	if isLoggableError(err) {
		f.log.ErrorContext(ctx, "Failed to close", "error", err)
	}
	return err
}

// IsDir implements File.
func (f *LogFile) IsDir() bool {
	return f.f.IsDir()
}

// Read implements File.
func (f *LogFile) Read(ctx context.Context, p []byte) (n int, err error) {
	ctx, cancel := context.WithTimeout(ctx, f.timeout)
	defer cancel()
	ctx, span := tracer.Start(ctx, "Read",
		trace.WithAttributes(
			attribute.String("filename", f.filename),
			attribute.Int("length", len(p)),
		),
	)
	defer func() {
		span.SetAttributes(attribute.Int("read", n))
		if err != nil {
			span.RecordError(err)
		}
		span.End()
	}()

	n, err = f.f.Read(ctx, p)
	if isLoggableError(err) {
		f.log.Error("Failed to read", "error", err)
	}
	return n, err
}

// ReadAt implements File.
func (f *LogFile) ReadAt(ctx context.Context, p []byte, off int64) (n int, err error) {
	ctx, cancel := context.WithTimeout(ctx, f.timeout)
	defer cancel()
	ctx, span := tracer.Start(ctx, "ReadAt",
		trace.WithAttributes(
			attribute.String("filename", f.filename),
			attribute.Int("length", len(p)),
		),
	)
	defer func() {
		span.SetAttributes(attribute.Int("read", n))
		if err != nil {
			span.RecordError(err)
		}
		span.End()
	}()

	n, err = f.f.ReadAt(ctx, p, off)
	if isLoggableError(err) {
		f.log.Error("Failed to read", "offset", off, "error", err)
	}
	return n, err
}

// Size implements File.
func (f *LogFile) Size() int64 {
	return f.f.Size()
}

// Stat implements File.
func (f *LogFile) Info() (fs.FileInfo, error) {
	info, err := f.f.Info()
	if isLoggableError(err) {
		f.log.Error("Failed to info", "error", err)
	}
	return info, err
}