Skip to content

Commit

Permalink
allow basic logging for mounts
Browse files Browse the repository at this point in the history
  • Loading branch information
ozkatz committed Apr 15, 2024
1 parent 5c19e88 commit 5e8609e
Show file tree
Hide file tree
Showing 7 changed files with 279 additions and 30 deletions.
5 changes: 1 addition & 4 deletions cmd/cat.go
Original file line number Diff line number Diff line change
Expand Up @@ -30,10 +30,7 @@ var catCmd = &cobra.Command{
_, _ = os.Stderr.WriteString(fmt.Sprintf("could not open zip file: %v\n", err))
os.Exit(1)
}
zip := zipfile.NewCentralDirectoryParser(&adapter{
f: obj,
ctx: ctx,
})
zip := zipfile.NewCentralDirectoryParser(zipfile.NewStorageAdapter(ctx, obj))
reader, err := zip.Read(internalPath)
if err != nil {
_, _ = os.Stderr.WriteString(fmt.Sprintf("could not open zip file stream: %v\n", err))
Expand Down
5 changes: 1 addition & 4 deletions cmd/common.go
Original file line number Diff line number Diff line change
Expand Up @@ -67,10 +67,7 @@ func getCdr(remoteFile string) []*zipfile.CDR {
_, _ = os.Stderr.WriteString(fmt.Sprintf("could not open remote zip file: %v\n", err))
os.Exit(1)
}
zip := zipfile.NewCentralDirectoryParser(zipfile.NewStorageAdapter(ctx, f))
f: obj,
ctx: ctx,
})
zip := zipfile.NewCentralDirectoryParser(zipfile.NewStorageAdapter(ctx, obj))

files, err := zip.GetCentralDirectory()
if err != nil {
Expand Down
8 changes: 8 additions & 0 deletions cmd/mount.go
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,10 @@ var mountCmd = &cobra.Command{
if err != nil {
die("could not parse command flags: %v\n", err)
}
logFile, err := cmd.Flags().GetString("log")
if err != nil {
die("could not parse command flags: %v\n", err)
}

serverCmd := []string{"mount-server", uri}
if cacheDir != "" {
Expand All @@ -95,6 +99,9 @@ var mountCmd = &cobra.Command{
}
callbackAddr := callbackListener.Addr().String()
serverCmd = append(serverCmd, "--callback-addr", callbackAddr)
if logFile != "" {
serverCmd = append(serverCmd, "--log", logFile)
}
serverStatus := getNFSServerCallback(callbackListener)
pid, err := mount.Daemonize(serverCmd...)
if err != nil {
Expand Down Expand Up @@ -135,6 +142,7 @@ var mountCmd = &cobra.Command{
func init() {
mountCmd.Flags().String("cache-dir", "", "directory to cache read files in")
mountCmd.Flags().StringP("listen", "l", MountServerBindAddress, "address to listen on")
mountCmd.Flags().String("log", "", "log file for the server to write to")
mountCmd.Flags().Bool("no-spawn", false, "will not spawn a new server, assume one is already running")
_ = mountCmd.Flags().MarkHidden("no-spawn")
rootCmd.AddCommand(mountCmd)
Expand Down
36 changes: 35 additions & 1 deletion cmd/mount_server.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ package cmd

import (
"fmt"
"io"
"log/slog"
"net"
"os"
Expand Down Expand Up @@ -43,6 +44,23 @@ func sendCallback(toAddr string, className nfsServerCallbackStatus, msg string)
return conn.Close()
}

func serverLogging(logFile string) (*slog.Logger, error) {
writer := io.Discard
var err error
if logFile != "" {
writer, err = os.OpenFile(logFile, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0755)
if err != nil {
return nil, err
}
}
opts := &slog.HandlerOptions{AddSource: false, Level: slog.LevelInfo}
if os.Getenv("CLOUDZIP_LOGGING") == "DEBUG" {
opts.Level = slog.LevelDebug
}
handler := slog.NewJSONHandler(writer, opts)
return slog.New(handler), nil
}

var mountServerCmd = &cobra.Command{
Use: "mount-server",
Hidden: true,
Expand All @@ -62,6 +80,10 @@ var mountServerCmd = &cobra.Command{
if err != nil {
die("could not parse command flags: %v\n", err)
}
logFile, err := cmd.Flags().GetString("log")
if err != nil {
die("could not parse command flags: %v\n", err)
}

// handle cache dir
if cacheDir == "" {
Expand Down Expand Up @@ -89,6 +111,14 @@ var mountServerCmd = &cobra.Command{
}
}

// setup logging
logger, err := serverLogging(logFile)
if err != nil {
if err != nil {
dieWithCallback(callbackAddr, "could not open log file %s: %v\n", logFile, err)
}
}

// bind to listen address
listener, err := net.Listen("tcp4", listenAddr)
if err != nil {
Expand All @@ -108,7 +138,10 @@ var mountServerCmd = &cobra.Command{
ctx, cancelFn := signal.NotifyContext(ctx, os.Interrupt) // SIGTERM
defer cancelFn()

handler := nfs.NewHandler(tree, nil)
handler := nfs.NewHandler(ctx, tree, &nfs.Options{
Logger: logger,
HandleCacheSize: nfs.DefaultHandleCacheSize,
})
go func() {
err = nfs.Serve(ctx, listener, handler)
if err != nil {
Expand All @@ -134,6 +167,7 @@ var mountServerCmd = &cobra.Command{
func init() {
mountServerCmd.Flags().String("cache-dir", "", "directory to cache read files in")
mountServerCmd.Flags().StringP("listen", "l", MountServerBindAddress, "address to listen on")
mountServerCmd.Flags().String("log", "", "optional log file to write to")
mountServerCmd.Flags().String("callback-addr", "", "callback address to report back to")
rootCmd.AddCommand(mountServerCmd)
}
221 changes: 221 additions & 0 deletions pkg/mount/nfs/logging.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,221 @@
package nfs

import (
"context"
"github.com/go-git/go-billy/v5"
"log/slog"
"os"
"time"
)

type loggingFs struct {
ctx context.Context
log *slog.Logger
next billy.Filesystem
}

type logOp struct {
startTime time.Time
ctx context.Context
opName string
log *slog.Logger
extra []any
}

func (op *logOp) Log(args ...any) {
args = append(args, "took_us", time.Since(op.startTime).Microseconds())
if op.extra != nil {
args = append(args, op.extra...)
}
op.log.DebugContext(op.ctx, op.opName, args...)
}

var _ billy.File = &loggingFile{}

type loggingFile struct {
ctx context.Context
log *slog.Logger
next billy.File
}

func (f *loggingFile) start(op string) *logOp {
return &logOp{
startTime: time.Now(),
ctx: f.ctx,
opName: op,
log: f.log,
extra: []any{"name", f.next.Name()},
}
}

func (f *loggingFile) Name() string {
return f.next.Name()
}

func (f *loggingFile) Write(p []byte) (n int, err error) {
op := f.start("file.Write")
n, err = f.next.Write(p)
op.Log("n", n, "p_len", len(p), "error", err)
return
}

func (f *loggingFile) Read(p []byte) (n int, err error) {
op := f.start("file.Read")
n, err = f.next.Read(p)
op.Log("n", n, "p_len", len(p), "error", err)
return
}

func (f *loggingFile) ReadAt(p []byte, off int64) (n int, err error) {
op := f.start("file.ReadAt")
n, err = f.next.ReadAt(p, off)
op.Log("n", n, "p_len", len(p), "offset", off, "error", err)
return
}

func (f *loggingFile) Seek(offset int64, whence int) (int64, error) {
op := f.start("file.Seek")
pos, err := f.next.Seek(offset, whence)
op.Log("offset", offset, "whence", whence, "pos", pos, "error", err)
return pos, err
}

func (f *loggingFile) Close() error {
op := f.start("file.Close")
err := f.next.Close()
op.Log("error", err)
return err
}

func (f *loggingFile) Lock() error {
op := f.start("file.Lock")
err := f.next.Lock()
op.Log("error", err)
return err
}

func (f *loggingFile) Unlock() error {
op := f.start("file.Unlock")
err := f.next.Unlock()
op.Log("error", err)
return err
}

func (f *loggingFile) Truncate(size int64) error {
op := f.start("file.Truncate")
err := f.next.Truncate(size)
op.Log("size", size, "error", err)
return err
}

func (fs *loggingFs) start(op string) *logOp {
return &logOp{
startTime: time.Now(),
ctx: fs.ctx,
opName: op,
log: fs.log,
}
}

func (fs *loggingFs) Create(filename string) (billy.File, error) {
op := fs.start("fs.Create")
f, err := fs.next.Create(filename)
op.Log("filename", filename, "error", err)
return &loggingFile{fs.ctx, fs.log, f}, err
}

func (fs *loggingFs) Open(filename string) (billy.File, error) {
op := fs.start("fs.Open")
f, err := fs.next.Open(filename)
op.Log("filename", filename, "error", err)
return &loggingFile{fs.ctx, fs.log, f}, err
}

func (fs *loggingFs) OpenFile(filename string, flag int, perm os.FileMode) (billy.File, error) {
op := fs.start("fs.OpenFile")
f, err := fs.next.OpenFile(filename, flag, perm)
op.Log("filename", filename, "flag", flag, "perm", perm, "error", err)
return &loggingFile{fs.ctx, fs.log, f}, err
}

func (fs *loggingFs) Stat(filename string) (os.FileInfo, error) {
op := fs.start("fs.Stat")
inf, err := fs.next.Stat(filename)
op.Log("filename", filename, "error", err)
return inf, err
}

func (fs *loggingFs) Rename(oldpath, newpath string) error {
op := fs.start("fs.Rename")
err := fs.next.Rename(oldpath, newpath)
op.Log("oldpath", oldpath, "newpath", newpath, "error", err)
return err
}

func (fs *loggingFs) Remove(filename string) error {
op := fs.start("fs.Remove")
err := fs.next.Remove(filename)
op.Log("filename", filename, "error", err)
return err
}

func (fs *loggingFs) Join(elem ...string) string {
return fs.next.Join(elem...)
}

func (fs *loggingFs) TempFile(dir, prefix string) (billy.File, error) {
op := fs.start("fs.TempFile")
f, err := fs.next.TempFile(dir, prefix)
op.Log("dir", dir, "prefix", prefix, "error", err)
return &loggingFile{fs.ctx, fs.log, f}, err
}

func (fs *loggingFs) ReadDir(path string) ([]os.FileInfo, error) {
op := fs.start("fs.Readdir")
files, err := fs.next.ReadDir(path)
op.Log("path", path, "error", err, "file_count", len(files))
return files, err
}

func (fs *loggingFs) MkdirAll(filename string, perm os.FileMode) error {
op := fs.start("fs.MkdirAll")
err := fs.next.MkdirAll(filename, perm)
op.Log("filename", filename, "perm", perm, "error", err)
return err
}

func (fs *loggingFs) Lstat(filename string) (os.FileInfo, error) {
op := fs.start("fs.Lstat")
info, err := fs.next.Lstat(filename)
op.Log("filename", filename, "error", err)
return info, err
}

func (fs *loggingFs) Symlink(target, link string) error {
op := fs.start("fs.Symlink")
err := fs.next.Symlink(target, link)
op.Log("target", target, "link", link, "error", err)
return err
}

func (fs *loggingFs) Readlink(link string) (string, error) {
op := fs.start("fs.Readlink")
target, err := fs.next.Readlink(link)
op.Log("link", link, "target", target, "error", err)
return target, err
}

func (fs *loggingFs) Chroot(path string) (billy.Filesystem, error) {
op := fs.start("fs.Chroot")
f, err := fs.next.Chroot(path)
op.Log("path", path, "error", err)
return f, err
}

func (fs *loggingFs) Root() string {
return fs.next.Root()
}

func LoggingFS(ctx context.Context, next billy.Filesystem, log *slog.Logger) billy.Filesystem {
return &loggingFs{ctx, log, next}
}
15 changes: 11 additions & 4 deletions pkg/mount/nfs/server.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ package nfs

import (
"context"
"log/slog"
"net"

"github.com/willscott/go-nfs"
Expand All @@ -18,19 +19,25 @@ func Serve(ctx context.Context, listener net.Listener, handler nfs.Handler) erro
return server.Serve(listener)
}

type NFSOptions struct {
type Options struct {
HandleCacheSize int
Logger *slog.Logger
}

const defaultHandleCacheSize = 1000000
const DefaultHandleCacheSize = 1000000

var DefaultOptions = &NFSOptions{HandleCacheSize: defaultHandleCacheSize}
var DefaultOptions = &Options{
HandleCacheSize: DefaultHandleCacheSize,
}

func NewHandler(tree index.Tree, opts *NFSOptions) nfs.Handler {
func NewHandler(ctx context.Context, tree index.Tree, opts *Options) nfs.Handler {
zipFs := NewZipFS(tree)
if opts == nil {
opts = DefaultOptions
}
if opts.Logger != nil {
zipFs = LoggingFS(ctx, zipFs, opts.Logger)
}
fsHandler := nfshelper.NewNullAuthHandler(zipFs)
return nfshelper.NewCachingHandler(fsHandler, opts.HandleCacheSize)
}
Loading

0 comments on commit 5e8609e

Please sign in to comment.