diff --git a/cmd/skywire-visor/commands/root.go b/cmd/skywire-visor/commands/root.go index 72ab969b5..a3dfc251e 100644 --- a/cmd/skywire-visor/commands/root.go +++ b/cmd/skywire-visor/commands/root.go @@ -2,10 +2,8 @@ package commands import ( "context" - "embed" "fmt" "io" - "io/fs" "io/ioutil" "net/http" _ "net/http/pprof" // nolint:gosec // https://golang.org/doc/diagnostics.html#profiling @@ -15,6 +13,9 @@ import ( "syscall" "time" + "embed" + "io/fs" + "github.com/pkg/profile" "github.com/skycoin/dmsg/buildinfo" "github.com/skycoin/dmsg/cmdutil" @@ -25,6 +26,7 @@ import ( "github.com/skycoin/skywire/pkg/restart" "github.com/skycoin/skywire/pkg/syslog" "github.com/skycoin/skywire/pkg/visor" + "github.com/skycoin/skywire/pkg/visor/logstore" "github.com/skycoin/skywire/pkg/visor/visorconfig" ) @@ -33,7 +35,8 @@ var uiAssets fs.FS var restartCtx = restart.CaptureContext() const ( - defaultConfigName = "skywire-config.json" + defaultConfigName = "skywire-config.json" + runtimeLogMaxEntries = 300 ) var ( @@ -61,6 +64,8 @@ var rootCmd = &cobra.Command{ Short: "Skywire visor", Run: func(_ *cobra.Command, args []string) { log := initLogger(tag, syslogAddr) + store, hook := logstore.MakeStore(runtimeLogMaxEntries) + log.AddHook(hook) delayDuration, err := time.ParseDuration(delay) if err != nil { @@ -117,6 +122,7 @@ var rootCmd = &cobra.Command{ if !ok { log.Fatal("Failed to start visor.") } + v.SetLogstore(store) if launchBrowser { runBrowser(conf, log) diff --git a/go.sum b/go.sum index e3a49dc30..6fc55219e 100644 --- a/go.sum +++ b/go.sum @@ -275,6 +275,7 @@ golang.org/x/crypto v0.0.0-20201208171446-5f87f3452ae9 h1:sYNJzB4J8toYPQTM6pAkcm golang.org/x/crypto v0.0.0-20201208171446-5f87f3452ae9/go.mod h1:jdWPYTVW3xRLrWPugEBEK3UY2ZEsg3UU495nc5E+M+I= golang.org/x/lint v0.0.0-20181026193005-c67002cb31c3/go.mod h1:UVdnD1Gm6xHRNCYTkRU2/jEulfH38KcIWyp/GAMgvoE= golang.org/x/lint v0.0.0-20190313153728-d0100b6bd8b3/go.mod h1:6SW0HCj/g11FgYtHlgUYUwCkIfeOF89ocIRzGO/8vkc= +golang.org/x/mod v0.2.0 h1:KU7oHjnv3XNWfa5COkzUifxZmxp1TyI7ImMXqFxLwvQ= golang.org/x/mod v0.2.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= golang.org/x/mod v0.3.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= golang.org/x/mod v0.4.2 h1:Gz96sIWK3OalVv/I/qNygP42zyoKp3xptRVCWRFEBvo= @@ -327,7 +328,6 @@ golang.org/x/text v0.3.2/go.mod h1:bEr9sfX3Q8Zfm5fL9x+3itogRgK3+ptLWKqgva+5dAk= golang.org/x/text v0.3.3 h1:cokOdA+Jmi5PJGXLlLllQSgYigAEfHXJAERHVMaCc2k= golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= golang.org/x/time v0.0.0-20190308202827-9d24e82272b4/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ= -golang.org/x/time v0.0.0-20191024005414-555d28b269f0 h1:/5xXl8Y5W96D+TtHSlonuFqGHIWVuyCkGJLwGh9JJFs= golang.org/x/time v0.0.0-20191024005414-555d28b269f0/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ= golang.org/x/tools v0.0.0-20180221164845-07fd8470d635/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= @@ -354,12 +354,10 @@ google.golang.org/protobuf v0.0.0-20200221191635-4d8936d0db64/go.mod h1:kwYJMbMJ google.golang.org/protobuf v0.0.0-20200228230310-ab0ca4ff8a60/go.mod h1:cfTl7dwQJ+fmap5saPgwCLgHXTUD7jkjRqWcaiX5VyM= google.golang.org/protobuf v1.20.1-0.20200309200217-e05f789c0967/go.mod h1:A+miEFZTKqfCUM6K7xSMQL9OKL/b6hQv+e19PK+JZNE= google.golang.org/protobuf v1.21.0/go.mod h1:47Nbq4nVaFHyn7ilMalzfO3qCViNmqZ2kzikPIcrTAo= -google.golang.org/protobuf v1.23.0 h1:4MY060fB1DLGMB/7MBTLnwQUY6+F09GEiz6SsrNqyzM= google.golang.org/protobuf v1.23.0/go.mod h1:EGpADcykh3NcUnDUJcl1+ZksZNG86OlYog2l/sGQquU= gopkg.in/alecthomas/kingpin.v2 v2.2.6/go.mod h1:FMv+mEhP44yOT+4EoQTLFTRgOQ1FBLkstjWtayDeSgw= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= -gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15 h1:YR8cESwS4TdDjEe65xsg0ogRM/Nc3DYOhEAlW+xobZo= gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/fsnotify.v1 v1.4.7/go.mod h1:Tz8NjZHkW78fSQdbUxIjBTcgA1z1m8ZHf0WmKUhAMys= gopkg.in/ini.v1 v1.51.0/go.mod h1:pNLf8WUiyNEtQjuu5G5vTm06TEv9tsIgeAvK8hOrP4k= diff --git a/pkg/visor/api.go b/pkg/visor/api.go index cbe28e8cf..d517899fb 100644 --- a/pkg/visor/api.go +++ b/pkg/visor/api.go @@ -69,6 +69,7 @@ type API interface { UpdateWithStatus(config updater.UpdateConfig) <-chan StatusMessage UpdateAvailable(channel updater.Channel) (*updater.Version, error) UpdateStatus() (string, error) + RuntimeLogs() (string, error) } // HealthCheckable resource returns its health status as an integer @@ -723,3 +724,13 @@ func (v *Visor) UpdateAvailable(channel updater.Channel) (*updater.Version, erro func (v *Visor) UpdateStatus() (string, error) { return v.updater.Status(), nil } + +// RuntimeLogs returns visor runtime logs +func (v *Visor) RuntimeLogs() (string, error) { + var builder strings.Builder + builder.WriteString("[") + logs, _ := v.logstore.GetLogs() + builder.WriteString(strings.Join(logs, ",")) + builder.WriteString("]") + return builder.String(), nil +} diff --git a/pkg/visor/hypervisor.go b/pkg/visor/hypervisor.go index b8c51ac9b..61a25a14f 100644 --- a/pkg/visor/hypervisor.go +++ b/pkg/visor/hypervisor.go @@ -257,6 +257,7 @@ func (hv *Hypervisor) makeMux() chi.Router { r.Get("/visors/{pk}/update/ws/running", hv.isVisorWSUpdateRunning()) r.Get("/visors/{pk}/update/available", hv.visorUpdateAvailable()) r.Get("/visors/{pk}/update/available/{channel}", hv.visorUpdateAvailable()) + r.Get("/visors/{pk}/runtime-logs", hv.getRuntimeLogs()) }) }) @@ -1315,6 +1316,22 @@ func (hv *Hypervisor) visorUpdateAvailable() http.HandlerFunc { }) } +func (hv *Hypervisor) getRuntimeLogs() http.HandlerFunc { + return hv.withCtx(hv.visorCtx, func(w http.ResponseWriter, r *http.Request, ctx *httpCtx) { + logs, err := ctx.API.RuntimeLogs() + if err != nil { + httputil.WriteJSON(w, r, http.StatusInternalServerError, err) + return + } + w.Header().Set("Content-Type", "application/json") + w.WriteHeader(http.StatusOK) + _, err = w.Write([]byte(logs)) + if err != nil { + hv.visor.log.Errorf("Cannot write response: %s", err) + } + }) +} + /* <<< Helper functions >>> */ diff --git a/pkg/visor/hypervisorconfig/config.go b/pkg/visor/hypervisorconfig/config.go index 637e815a8..1b165cc33 100644 --- a/pkg/visor/hypervisorconfig/config.go +++ b/pkg/visor/hypervisorconfig/config.go @@ -3,13 +3,14 @@ package hypervisorconfig import ( "encoding/hex" "encoding/json" - "io/fs" "log" "net/http" "os" "path/filepath" "time" + "io/fs" + "github.com/skycoin/dmsg/cipher" "github.com/skycoin/skywire/pkg/skyenv" diff --git a/pkg/visor/logstore/logstore.go b/pkg/visor/logstore/logstore.go new file mode 100644 index 000000000..c9e06438a --- /dev/null +++ b/pkg/visor/logstore/logstore.go @@ -0,0 +1,81 @@ +package logstore + +import ( + "github.com/sirupsen/logrus" +) + +// LogRealLineKey is a key in the log entry that denotes real log line number +// in the total log (not limited by capacity of runtime log store) +const LogRealLineKey = "log_line" + +// Store is in-memory log store that returns all logs as a single string +type Store interface { + // get logs returns stored logs and the number of log entries overwritten + // due to insufficient capacity. + // returned number n means that n log entries have been dropped and the oldest + // log entry is (n+1)th + GetLogs() ([]string, int64) +} + +// MakeStore returns a new store that will hold up to max entries, +// overwriting the oldest entry when over the capacity +// returned hook should be registered in logrus master logger to +// store log entries +func MakeStore(max int) (Store, logrus.Hook) { + entries := make([]string, max) + formatter := &logrus.JSONFormatter{} + store := &store{cap: int64(max), entries: entries, formatter: formatter} + return store, store +} + +type store struct { + // max number of entries to hold simultaneously + cap int64 + // number of the next entry to come (also number of entries processed since the beginning) + entryNum int64 + entries []string + formatter logrus.Formatter +} + +// collect log lines into a single string, starting at from (inclusive) +// and ending at to (not inclusive) +func (s *store) collectLogs(from, to int64) []string { + logs := make([]string, 0) + for i := from; i < to; i++ { + logs = append(logs, s.entries[i]) + } + return logs +} + +// GetLogs returns most recent log lines (up to cap log lines is stored +func (s *store) GetLogs() ([]string, int64) { + if s.entryNum < s.cap { + return s.collectLogs(0, s.entryNum), 0 + } + idx := s.entryNum % s.cap + logs := s.collectLogs(idx, s.cap) + logs = append(logs, s.collectLogs(0, idx)...) + return logs, s.entryNum - s.cap +} + +// Levels implements logrus.Hook interface. It denotes log levels +// that we are interested in +func (s *store) Levels() []logrus.Level { + return logrus.AllLevels +} + +// Fire implements logrus.Hook interface to process new log entry +// that we simply store +func (s *store) Fire(entry *logrus.Entry) error { + idx := s.entryNum % s.cap + e := entry.WithField(LogRealLineKey, s.entryNum+1) + e.Level = entry.Level + e.Message = entry.Message + bs, err := s.formatter.Format(e) + if err != nil { + return err + } + s.entries[idx] = string(bs) + s.entryNum++ + return nil +} diff --git a/pkg/visor/rpc.go b/pkg/visor/rpc.go index d8c88e9ff..553050f6d 100644 --- a/pkg/visor/rpc.go +++ b/pkg/visor/rpc.go @@ -538,3 +538,9 @@ func (r *RPC) UpdateStatus(_ *struct{}, status *string) (err error) { *status, err = r.visor.UpdateStatus() return } + +// RuntimeLogs returns visor runtime logs +func (r *RPC) RuntimeLogs(_ *struct{}, logs *string) (err error) { + *logs, err = r.visor.RuntimeLogs() + return +} diff --git a/pkg/visor/rpc_client.go b/pkg/visor/rpc_client.go index 16a013418..2664ba9a8 100644 --- a/pkg/visor/rpc_client.go +++ b/pkg/visor/rpc_client.go @@ -331,6 +331,13 @@ func (rc *rpcClient) Update(config updater.UpdateConfig) (bool, error) { return updated, err } +// Update calls Update. +func (rc *rpcClient) RuntimeLogs() (string, error) { + var logs string + err := rc.Call("RuntimeLogs", &struct{}{}, &logs) + return logs, err +} + // StatusMessage defines a status of visor update. type StatusMessage struct { Text string @@ -911,3 +918,8 @@ func (mc *mockRPCClient) UpdateAvailable(_ updater.Channel) (*updater.Version, e func (mc *mockRPCClient) UpdateStatus() (string, error) { return "", nil } + +// UpdateStatus implements API. +func (mc *mockRPCClient) RuntimeLogs() (string, error) { + return "", nil +} diff --git a/pkg/visor/visor.go b/pkg/visor/visor.go index 3eb3df8e1..3cdaaefc3 100644 --- a/pkg/visor/visor.go +++ b/pkg/visor/visor.go @@ -26,6 +26,7 @@ import ( "github.com/skycoin/skywire/pkg/snet/arclient" "github.com/skycoin/skywire/pkg/transport" "github.com/skycoin/skywire/pkg/util/updater" + "github.com/skycoin/skywire/pkg/visor/logstore" "github.com/skycoin/skywire/pkg/visor/visorconfig" ) @@ -48,8 +49,9 @@ type Visor struct { reportCh chan vReport closeStack []closeElem - conf *visorconfig.V1 - log *logging.Logger + conf *visorconfig.V1 + log *logging.Logger + logstore logstore.Store startedAt time.Time restartCtx *restart.Context @@ -212,6 +214,11 @@ func (v *Visor) Close() error { return nil } +// SetLogstore sets visor runtime logstore +func (v *Visor) SetLogstore(store logstore.Store) { + v.logstore = store +} + // tpDiscClient is a convenience function to obtain transport discovery client. func (v *Visor) tpDiscClient() transport.DiscoveryClient { return v.tpM.Conf.DiscoveryClient