From 7bb411e7a43edb93375f068e985db708b7186fa5 Mon Sep 17 00:00:00 2001 From: royalcat <k.adamovich20@gmail.com> Date: Sat, 6 Apr 2024 16:50:43 +0300 Subject: [PATCH 1/4] pyroscope --- src/telemetry/setup.go | 57 +++++++++++++++++++++++++++++++++++++++++- 1 file changed, 56 insertions(+), 1 deletion(-) diff --git a/src/telemetry/setup.go b/src/telemetry/setup.go index 5e86ba0..c83663a 100644 --- a/src/telemetry/setup.go +++ b/src/telemetry/setup.go @@ -2,14 +2,18 @@ package telemetry import ( "context" + "fmt" "log/slog" "os" + "runtime" "git.kmsign.ru/royalcat/tstor/pkg/rlog" "github.com/agoda-com/opentelemetry-go/otelslog" "github.com/agoda-com/opentelemetry-logs-go/exporters/otlp/otlplogs" "github.com/agoda-com/opentelemetry-logs-go/exporters/otlp/otlplogs/otlplogshttp" logsdk "github.com/agoda-com/opentelemetry-logs-go/sdk/logs" + otelpyroscope "github.com/grafana/otel-profiling-go" + "github.com/grafana/pyroscope-go" "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp" "go.opentelemetry.io/otel/exporters/prometheus" @@ -99,7 +103,8 @@ func Setup(ctx context.Context, endpoint string) (*Client, error) { trace.WithBatcher(traceExporter), trace.WithResource(r), ) - otel.SetTracerProvider(client.tracerProvider) + // otel.SetTracerProvider(client.tracerProvider) + otel.SetTracerProvider(otelpyroscope.NewTracerProvider(client.tracerProvider)) log.Info("otel tracing provider initialized") logExporter, err := otlplogs.NewExporter(ctx, @@ -122,5 +127,55 @@ func Setup(ctx context.Context, endpoint string) (*Client, error) { ) client.log = slog.Default() + runtime.SetMutexProfileFraction(5) + runtime.SetBlockProfileRate(5) + _, err = pyroscope.Start(pyroscope.Config{ + ApplicationName: appName, + // replace this with the address of pyroscope server + ServerAddress: "https://pyroscope.kmsign.ru", + // you can disable logging by setting this to nil + Logger: &pyroscopeLogger{ + log: rlog.ComponentLog("metrics.pyroscope"), + }, + ProfileTypes: []pyroscope.ProfileType{ + // these profile types are enabled by default: + pyroscope.ProfileCPU, + pyroscope.ProfileAllocObjects, + pyroscope.ProfileAllocSpace, + pyroscope.ProfileInuseObjects, + pyroscope.ProfileInuseSpace, + // these profile types are optional: + // pyroscope.ProfileGoroutines, + // pyroscope.ProfileMutexCount, + // pyroscope.ProfileMutexDuration, + // pyroscope.ProfileBlockCount, + // pyroscope.ProfileBlockDuration, + }, + }) + if err != nil { + return client, nil + } + return client, nil } + +type pyroscopeLogger struct { + log *slog.Logger +} + +var _ pyroscope.Logger = (*pyroscopeLogger)(nil) + +// Debugf implements pyroscope.Logger. +func (p *pyroscopeLogger) Debugf(msg string, args ...any) { + p.log.Debug(fmt.Sprintf(msg, args...)) +} + +// Errorf implements pyroscope.Logger. +func (p *pyroscopeLogger) Errorf(msg string, args ...any) { + p.log.Error(fmt.Sprintf(msg, args...)) +} + +// Infof implements pyroscope.Logger. +func (p *pyroscopeLogger) Infof(msg string, args ...any) { + p.log.Info(fmt.Sprintf(msg, args...)) +} From f4f60df6b2d399594f3b82f96fc921e918c46092 Mon Sep 17 00:00:00 2001 From: royalcat <k.adamovich20@gmail.com> Date: Sat, 6 Apr 2024 16:51:17 +0300 Subject: [PATCH 2/4] nfs timeout error --- pkg/go-nfs/nfs_ongetattr.go | 2 +- pkg/go-nfs/nfs_onread.go | 2 +- pkg/go-nfs/nfs_onreaddir.go | 2 +- pkg/go-nfs/nfs_onreadlink.go | 2 +- pkg/go-nfs/nfs_onremove.go | 4 ++-- pkg/go-nfs/nfs_onrename.go | 6 +++--- pkg/go-nfs/nfs_onsetattr.go | 2 +- pkg/go-nfs/nfs_onwrite.go | 2 +- pkg/go-nfs/nfsinterface.go | 2 ++ 9 files changed, 13 insertions(+), 11 deletions(-) diff --git a/pkg/go-nfs/nfs_ongetattr.go b/pkg/go-nfs/nfs_ongetattr.go index 40c4148..b936c06 100644 --- a/pkg/go-nfs/nfs_ongetattr.go +++ b/pkg/go-nfs/nfs_ongetattr.go @@ -27,7 +27,7 @@ func onGetAttr(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusNoEnt, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusIO, err} } diff --git a/pkg/go-nfs/nfs_onread.go b/pkg/go-nfs/nfs_onread.go index 8616acd..ee8e199 100644 --- a/pkg/go-nfs/nfs_onread.go +++ b/pkg/go-nfs/nfs_onread.go @@ -48,7 +48,7 @@ func onRead(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusNoEnt, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusAccess, err} } diff --git a/pkg/go-nfs/nfs_onreaddir.go b/pkg/go-nfs/nfs_onreaddir.go index 2769d02..7f90a63 100644 --- a/pkg/go-nfs/nfs_onreaddir.go +++ b/pkg/go-nfs/nfs_onreaddir.go @@ -160,7 +160,7 @@ func getDirListingWithVerifier(ctx context.Context, userHandle Handler, fsHandle return nil, 0, &NFSStatusError{NFSStatusAccess, err} } if errors.Is(err, context.DeadlineExceeded) { - return nil, 0, &NFSStatusError{NFSStatusJukebox, err} + return nil, 0, &NFSStatusError{timeoutStatus, err} } return nil, 0, &NFSStatusError{NFSStatusIO, err} } diff --git a/pkg/go-nfs/nfs_onreadlink.go b/pkg/go-nfs/nfs_onreadlink.go index 887047a..691124e 100644 --- a/pkg/go-nfs/nfs_onreadlink.go +++ b/pkg/go-nfs/nfs_onreadlink.go @@ -31,7 +31,7 @@ func onReadLink(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusNoEnt, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusAccess, err} diff --git a/pkg/go-nfs/nfs_onremove.go b/pkg/go-nfs/nfs_onremove.go index bffb446..b6a892b 100644 --- a/pkg/go-nfs/nfs_onremove.go +++ b/pkg/go-nfs/nfs_onremove.go @@ -39,7 +39,7 @@ func onRemove(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusAccess, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusIO, err} } @@ -60,7 +60,7 @@ func onRemove(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusAccess, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusIO, err} } diff --git a/pkg/go-nfs/nfs_onrename.go b/pkg/go-nfs/nfs_onrename.go index dc0d463..9ebcfb4 100644 --- a/pkg/go-nfs/nfs_onrename.go +++ b/pkg/go-nfs/nfs_onrename.go @@ -53,7 +53,7 @@ func onRename(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusNoEnt, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusIO, err} } @@ -69,7 +69,7 @@ func onRename(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusNoEnt, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusIO, err} } @@ -92,7 +92,7 @@ func onRename(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusAccess, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusIO, err} } diff --git a/pkg/go-nfs/nfs_onsetattr.go b/pkg/go-nfs/nfs_onsetattr.go index cc2c202..366773b 100644 --- a/pkg/go-nfs/nfs_onsetattr.go +++ b/pkg/go-nfs/nfs_onsetattr.go @@ -33,7 +33,7 @@ func onSetAttr(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusNoEnt, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusAccess, err} } diff --git a/pkg/go-nfs/nfs_onwrite.go b/pkg/go-nfs/nfs_onwrite.go index cfe2eb4..a7e5dd0 100644 --- a/pkg/go-nfs/nfs_onwrite.go +++ b/pkg/go-nfs/nfs_onwrite.go @@ -58,7 +58,7 @@ func onWrite(ctx context.Context, w *response, userHandle Handler) error { return &NFSStatusError{NFSStatusNoEnt, err} } if errors.Is(err, context.DeadlineExceeded) { - return &NFSStatusError{NFSStatusJukebox, err} + return &NFSStatusError{timeoutStatus, err} } return &NFSStatusError{NFSStatusAccess, err} } diff --git a/pkg/go-nfs/nfsinterface.go b/pkg/go-nfs/nfsinterface.go index cf439af..be7ae14 100644 --- a/pkg/go-nfs/nfsinterface.go +++ b/pkg/go-nfs/nfsinterface.go @@ -80,6 +80,8 @@ func (n NFSProcedure) String() string { } } +const timeoutStatus = NFSStatusIO + // NFSStatus (nfsstat3) is a result code for nfs rpc calls type NFSStatus uint32 From c1003c3314939e1d25fc38a3f8c9e98a6931c896 Mon Sep 17 00:00:00 2001 From: royalcat <k.adamovich20@gmail.com> Date: Sat, 6 Apr 2024 16:51:24 +0300 Subject: [PATCH 3/4] fix --- go.mod | 3 +++ go.sum | 13 +++++++++++++ 2 files changed, 16 insertions(+) diff --git a/go.mod b/go.mod index 6cbec8e..5ea10df 100644 --- a/go.mod +++ b/go.mod @@ -20,6 +20,8 @@ require ( github.com/go-git/go-billy/v5 v5.5.0 github.com/gofrs/uuid/v5 v5.0.0 github.com/google/uuid v1.5.0 + github.com/grafana/otel-profiling-go v0.5.1 + github.com/grafana/pyroscope-go v1.1.1 github.com/hashicorp/go-multierror v1.1.1 github.com/hashicorp/golang-lru/v2 v2.0.7 github.com/knadh/koanf/parsers/yaml v0.1.0 @@ -106,6 +108,7 @@ require ( github.com/google/btree v1.1.2 // indirect github.com/google/flatbuffers v2.0.8+incompatible // indirect github.com/gorilla/websocket v1.5.0 // indirect + github.com/grafana/pyroscope-go/godeltaprof v0.1.6 // indirect github.com/grpc-ecosystem/grpc-gateway/v2 v2.19.0 // indirect github.com/hashicorp/errwrap v1.0.0 // indirect github.com/huandu/xstrings v1.3.2 // indirect diff --git a/go.sum b/go.sum index 2cf862e..227ad50 100644 --- a/go.sum +++ b/go.sum @@ -223,6 +223,7 @@ github.com/go-llsqlite/crawshaw v0.4.0/go.mod h1:/YJdV7uBQaYDE0fwe4z3wwJIZBJxdYz github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9GBnD5lWE= github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk= github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= +github.com/go-logr/logr v1.3.0/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= github.com/go-logr/logr v1.4.1 h1:pKouT5E8xu9zeFC39JXRDukb6JFQPXM5p5I91188VAQ= github.com/go-logr/logr v1.4.1/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= @@ -319,6 +320,12 @@ github.com/gorilla/context v1.1.1/go.mod h1:kBGZzfjB9CEq2AlWe17Uuf7NDRt0dE0s8S51 github.com/gorilla/mux v1.6.2/go.mod h1:1lud6UwP+6orDFRuTfBEV8e9/aOM/c4fVVCaMa2zaAs= github.com/gorilla/websocket v1.5.0 h1:PPwGk2jz7EePpoHN/+ClbZu8SPxiqlu12wZP/3sWmnc= github.com/gorilla/websocket v1.5.0/go.mod h1:YR8l580nyteQvAITg2hZ9XVh4b55+EU/adAjf1fMHhE= +github.com/grafana/otel-profiling-go v0.5.1 h1:stVPKAFZSa7eGiqbYuG25VcqYksR6iWvF3YH66t4qL8= +github.com/grafana/otel-profiling-go v0.5.1/go.mod h1:ftN/t5A/4gQI19/8MoWurBEtC6gFw8Dns1sJZ9W4Tls= +github.com/grafana/pyroscope-go v1.1.1 h1:PQoUU9oWtO3ve/fgIiklYuGilvsm8qaGhlY4Vw6MAcQ= +github.com/grafana/pyroscope-go v1.1.1/go.mod h1:Mw26jU7jsL/KStNSGGuuVYdUq7Qghem5P8aXYXSXG88= +github.com/grafana/pyroscope-go/godeltaprof v0.1.6 h1:nEdZ8louGAplSvIJi1HVp7kWvFvdiiYg3COLlTwJiFo= +github.com/grafana/pyroscope-go/godeltaprof v0.1.6/go.mod h1:Tk376Nbldo4Cha9RgiU7ik8WKFkNpfds98aUzS8omLE= github.com/grpc-ecosystem/grpc-gateway/v2 v2.19.0 h1:Wqo399gCIufwto+VfwCSvsnfGpF/w5E9CNxSwbpD6No= github.com/grpc-ecosystem/grpc-gateway/v2 v2.19.0/go.mod h1:qmOFXW2epJhM0qSnUUYpldc7gVz2KMQwJ/QYCDIa7XU= github.com/hashicorp/errwrap v1.0.0 h1:hLrqtEDnRye3+sgx6z4qVLNuviH3MR5aQ0ykNJa/UYA= @@ -351,6 +358,7 @@ github.com/jtolds/gls v4.20.0+incompatible/go.mod h1:QJZ7F/aHp+rZTRtaJ1ow/lLfFfV github.com/julienschmidt/httprouter v1.2.0/go.mod h1:SYymIcj16QtmaHHD7aYtjjsJG7VTCxuUUipMqKk8s4w= github.com/kisielk/errcheck v1.5.0/go.mod h1:pFxgyoBC7bSaBwPgfKdkLd5X25qrDl4LWUI2bnpBCr8= github.com/kisielk/gotool v1.0.0/go.mod h1:XhKaO+MFFWcvkIS/tQcRk01m1F5IRFswLeQ+oQHNcck= +github.com/klauspost/compress v1.17.3/go.mod h1:/dCuZOvVtNoHsyb+cuJD3itjs3NbnF6KH9zAO4BDxPM= github.com/klauspost/compress v1.17.4 h1:Ej5ixsIri7BrIjBkRZLTo6ghwrEtHFk7ijlczPW4fZ4= github.com/klauspost/compress v1.17.4/go.mod h1:/dCuZOvVtNoHsyb+cuJD3itjs3NbnF6KH9zAO4BDxPM= github.com/klauspost/cpuid/v2 v2.0.9/go.mod h1:FInQzS24/EEf25PyTYn52gqo7WaD8xa0213Md/qVLRg= @@ -631,6 +639,7 @@ go.opencensus.io v0.24.0 h1:y73uSU6J157QMP2kn2r30vwW1A2W2WFwSCGnAVxeaD0= go.opencensus.io v0.24.0/go.mod h1:vNK8G9p7aAivkbmorf4v+7Hgx+Zs0yY+0fOtgBfjQKo= go.opentelemetry.io/contrib v1.21.1 h1:/U05KZ31iqMqAowhtW10cDPAViNY0tnpAacUgYBmuj8= go.opentelemetry.io/contrib v1.21.1/go.mod h1:usW9bPlrjHiJFbK0a6yK/M5wNHs3nLmtrT3vzhoD3co= +go.opentelemetry.io/otel v1.21.0/go.mod h1:QZzNPQPm1zLX4gZK4cMi+71eaorMSGT3A4znnUvNNEo= go.opentelemetry.io/otel v1.24.0 h1:0LAOdjNmQeSTzGBzduGe/rU4tZhMwL5rWgtp9Ku5Jfo= go.opentelemetry.io/otel v1.24.0/go.mod h1:W7b9Ozg4nkF5tWI5zsXkaKKDjdVjpD4oAt9Qi/MArHo= go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.24.0 h1:t6wl9SPayj+c7lEIFgm4ooDBZVb01IhLB4InpomhRw8= @@ -639,12 +648,15 @@ go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.24.0 h1:Xw8U6 go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.24.0/go.mod h1:6KW1Fm6R/s6Z3PGXwSJN2K4eT6wQB3vXX6CVnYX9NmM= go.opentelemetry.io/otel/exporters/prometheus v0.46.0 h1:I8WIFXR351FoLJYuloU4EgXbtNX2URfU/85pUPheIEQ= go.opentelemetry.io/otel/exporters/prometheus v0.46.0/go.mod h1:ztwVUHe5DTR/1v7PeuGRnU5Bbd4QKYwApWmuutKsJSs= +go.opentelemetry.io/otel/metric v1.21.0/go.mod h1:o1p3CA8nNHW8j5yuQLdc1eeqEaPfzug24uvsyIEJRWM= go.opentelemetry.io/otel/metric v1.24.0 h1:6EhoGWWK28x1fbpA4tYTOWBkPefTDQnb8WSGXlc88kI= go.opentelemetry.io/otel/metric v1.24.0/go.mod h1:VYhLe1rFfxuTXLgj4CBiyz+9WYBA8pNGJgDcSFRKBco= +go.opentelemetry.io/otel/sdk v1.21.0/go.mod h1:Nna6Yv7PWTdgJHVRD9hIYywQBRx7pbox6nwBnZIxl/E= go.opentelemetry.io/otel/sdk v1.24.0 h1:YMPPDNymmQN3ZgczicBY3B6sf9n62Dlj9pWD3ucgoDw= go.opentelemetry.io/otel/sdk v1.24.0/go.mod h1:KVrIYw6tEubO9E96HQpcmpTKDVn9gdv35HoYiQWGDFg= go.opentelemetry.io/otel/sdk/metric v1.24.0 h1:yyMQrPzF+k88/DbH7o4FMAs80puqd+9osbiBrJrz/w8= go.opentelemetry.io/otel/sdk/metric v1.24.0/go.mod h1:I6Y5FjH6rvEnTTAYQz3Mmv2kl6Ek5IIrmwTLqMrrOE0= +go.opentelemetry.io/otel/trace v1.21.0/go.mod h1:LGbsEB0f9LGjN+OZaQQ26sohbOmiMR+BaslueVtS/qQ= go.opentelemetry.io/otel/trace v1.24.0 h1:CsKnnL4dUAr/0llH9FKuc698G04IrpWV0MQA/Y1YELI= go.opentelemetry.io/otel/trace v1.24.0/go.mod h1:HPc3Xr/cOApsBI154IU0OI0HJexz+aw5uPdbs3UCjNU= go.opentelemetry.io/proto/otlp v1.1.0 h1:2Di21piLrCqJ3U3eXGCTPHE9R8Nh+0uglSnOyxikMeI= @@ -804,6 +816,7 @@ golang.org/x/sys v0.4.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.14.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= golang.org/x/sys v0.17.0 h1:25cE3gD+tdBA7lp7QfhuV+rJiE9YXTcS3VG1SqssI/Y= golang.org/x/sys v0.17.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= From bcda69daadfc194d2da17ecf15a0290d79e5075e Mon Sep 17 00:00:00 2001 From: royalcat <k.adamovich20@gmail.com> Date: Sat, 6 Apr 2024 16:51:36 +0300 Subject: [PATCH 4/4] sub timeout for fs init --- pkg/rlog/rlog.go | 4 ---- src/host/vfs/log.go | 37 +++++++++++++++++++++---------------- src/host/vfs/resolver.go | 23 ++++++++++++++++------- src/host/vfs/torrent.go | 10 +++++++++- src/host/vfs/utils.go | 11 +++++++++++ 5 files changed, 57 insertions(+), 28 deletions(-) diff --git a/pkg/rlog/rlog.go b/pkg/rlog/rlog.go index c8e1136..cbe6b75 100644 --- a/pkg/rlog/rlog.go +++ b/pkg/rlog/rlog.go @@ -34,10 +34,6 @@ func ComponentLog(name string) *slog.Logger { return defaultLogger.With(slog.String("component", name)) } -func ServiceLog(name string) *slog.Logger { - return ComponentLog("service/" + name) -} - func FunctionLog(log *slog.Logger, name string) *slog.Logger { return log.With(slog.String("function", name)) } diff --git a/src/host/vfs/log.go b/src/host/vfs/log.go index 1c19e1f..c5519ed 100644 --- a/src/host/vfs/log.go +++ b/src/host/vfs/log.go @@ -2,6 +2,7 @@ package vfs import ( "context" + "errors" "io/fs" "log/slog" "reflect" @@ -20,11 +21,15 @@ type LogFS struct { readTimeout time.Duration } +func isLoggableError(err error) bool { + return err != nil && !errors.Is(err, fs.ErrNotExist) +} + var _ Filesystem = (*LogFS)(nil) -func WrapLogFS(fs Filesystem) *LogFS { +func WrapLogFS(vfs Filesystem) *LogFS { return &LogFS{ - fs: fs, + fs: vfs, log: rlog.ComponentLog("fs"), timeout: time.Minute * 3, readTimeout: time.Minute, @@ -96,7 +101,7 @@ func (fs *LogFS) Open(ctx context.Context, filename string) (file File, err erro }() file, err = fs.fs.Open(ctx, filename) - if err != nil { + if isLoggableError(err) { fs.log.With("filename", filename).Error("Failed to open file") } file = WrapLogFile(file, filename, fs.log, fs.readTimeout) @@ -118,18 +123,18 @@ func (fs *LogFS) ReadDir(ctx context.Context, path string) (entries []fs.DirEntr }() entries, err = fs.fs.ReadDir(ctx, path) - if err != nil { + 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 (fs *LogFS) Stat(ctx context.Context, filename string) (info fs.FileInfo, err error) { - ctx, cancel := context.WithTimeout(ctx, fs.timeout) +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", - fs.traceAttrs(attribute.String("filename", filename)), + lfs.traceAttrs(attribute.String("filename", filename)), ) defer func() { if err != nil { @@ -138,9 +143,9 @@ func (fs *LogFS) Stat(ctx context.Context, filename string) (info fs.FileInfo, e span.End() }() - info, err = fs.fs.Stat(ctx, filename) - if err != nil { - fs.log.Error("Failed to stat", "filename", filename, "error", err) + info, err = lfs.fs.Stat(ctx, filename) + if isLoggableError(err) { + lfs.log.Error("Failed to stat", "filename", filename, "error", err) } return info, err } @@ -160,7 +165,7 @@ func (fs *LogFS) Unlink(ctx context.Context, filename string) (err error) { }() err = fs.fs.Unlink(ctx, filename) - if err != nil { + if isLoggableError(err) { fs.log.Error("Failed to stat", "filename", filename, "error", err) } return err @@ -210,7 +215,7 @@ func (f *LogFile) Close(ctx context.Context) (err error) { }() err = f.f.Close(ctx) - if err != nil { + if isLoggableError(err) { f.log.ErrorContext(ctx, "Failed to close", "error", err) } return err @@ -240,7 +245,7 @@ func (f *LogFile) Read(ctx context.Context, p []byte) (n int, err error) { }() n, err = f.f.Read(ctx, p) - if err != nil { + if isLoggableError(err) { f.log.Error("Failed to read", "error", err) } return n, err @@ -265,7 +270,7 @@ func (f *LogFile) ReadAt(ctx context.Context, p []byte, off int64) (n int, err e }() n, err = f.f.ReadAt(ctx, p, off) - if err != nil { + if isLoggableError(err) { f.log.Error("Failed to read", "offset", off, "error", err) } return n, err @@ -279,8 +284,8 @@ func (f *LogFile) Size() int64 { // Stat implements File. func (f *LogFile) Info() (fs.FileInfo, error) { info, err := f.f.Info() - if err != nil { - f.log.Error("Failed to read", "error", err) + if isLoggableError(err) { + f.log.Error("Failed to info", "error", err) } return info, err } diff --git a/src/host/vfs/resolver.go b/src/host/vfs/resolver.go index 6573ab5..de028e5 100644 --- a/src/host/vfs/resolver.go +++ b/src/host/vfs/resolver.go @@ -119,17 +119,26 @@ func (r *ResolverFS) ReadDir(ctx context.Context, dir string) ([]fs.DirEntry, er return nil, err } defer file.Close(ctx) - nestedfs, err := r.resolver.nestedFs(ctx, filepath, file) - if err != nil { - if errors.Is(err, context.DeadlineExceeded) { - r.log.ErrorContext(ctx, "creating fs timed out", "filename", e.Name()) - continue - } + err = func() error { + factoryCtx, cancel := subTimeout(ctx) + defer cancel() + nestedfs, err := r.resolver.nestedFs(factoryCtx, filepath, file) + if err != nil { + if errors.Is(err, context.DeadlineExceeded) { + r.log.ErrorContext(ctx, "creating fs timed out", "filename", e.Name()) + return nil + } + + return err + } + out = append(out, nestedfs) + return nil + }() + if err != nil { return nil, err } - out = append(out, nestedfs) } else { out = append(out, e) } diff --git a/src/host/vfs/torrent.go b/src/host/vfs/torrent.go index 88bd057..dd75760 100644 --- a/src/host/vfs/torrent.go +++ b/src/host/vfs/torrent.go @@ -2,6 +2,7 @@ package vfs import ( "context" + "fmt" "io" "io/fs" "path" @@ -413,7 +414,14 @@ func openTorrentFile(ctx context.Context, name string, file *torrent.File) (*tor r := file.NewReader() r.SetReadahead(1024 * 1024 * 16) // TODO configurable - // r.SetResponsive() + _, err := r.ReadContext(ctx, make([]byte, 128)) + if err != nil && err != io.EOF { + return nil, fmt.Errorf("failed initial file read: %w", err) + } + _, err = r.Seek(0, io.SeekStart) + if err != nil { + return nil, fmt.Errorf("failed seeking to start, after initial read: %w", err) + } return &torrentFile{ name: name, diff --git a/src/host/vfs/utils.go b/src/host/vfs/utils.go index 0cfca90..bbe8cbb 100644 --- a/src/host/vfs/utils.go +++ b/src/host/vfs/utils.go @@ -1,9 +1,11 @@ package vfs import ( + "context" "path" "strings" "sync" + "time" ) const Separator = "/" @@ -58,3 +60,12 @@ func OnceValueWOErr[T any](f func() (T, error)) func() (T, error) { return r1, err } } + +func subTimeout(ctx context.Context) (context.Context, context.CancelFunc) { + if deadline, ok := ctx.Deadline(); ok { + timeout := time.Until(deadline) / 2 + return context.WithTimeout(ctx, timeout) + } + + return ctx, func() {} +}