From a01b917d6d3f1bde158d194de424514266412811 Mon Sep 17 00:00:00 2001 From: Sir Darkrengarius Date: Wed, 23 Oct 2019 18:02:52 +0300 Subject: [PATCH] Add old app logger --- cmd/apps/skychat/chat.go | 5 +- pkg/app2/log.go | 49 +++++++++++ pkg/app2/log_store.go | 167 +++++++++++++++++++++++++++++++++++++ pkg/app2/log_store_test.go | 56 +++++++++++++ pkg/app2/log_test.go | 38 +++++++++ 5 files changed, 313 insertions(+), 2 deletions(-) create mode 100644 pkg/app2/log.go create mode 100644 pkg/app2/log_store.go create mode 100644 pkg/app2/log_store_test.go create mode 100644 pkg/app2/log_test.go diff --git a/cmd/apps/skychat/chat.go b/cmd/apps/skychat/chat.go index 70bb19373..6d9872985 100644 --- a/cmd/apps/skychat/chat.go +++ b/cmd/apps/skychat/chat.go @@ -14,11 +14,12 @@ import ( "sync" "time" + "github.com/skycoin/skywire/pkg/app2" + "github.com/skycoin/dmsg/cipher" "github.com/skycoin/skycoin/src/util/logging" "github.com/skycoin/skywire/internal/netutil" - "github.com/skycoin/skywire/pkg/app" "github.com/skycoin/skywire/pkg/routing" ) @@ -26,7 +27,7 @@ var addr = flag.String("addr", ":8000", "address to bind") var r = netutil.NewRetrier(50*time.Millisecond, 5, 2) var ( - chatApp *app.App + chatApp *app2.Client clientCh chan string chatConns map[cipher.PubKey]net.Conn connsMu sync.Mutex diff --git a/pkg/app2/log.go b/pkg/app2/log.go new file mode 100644 index 000000000..ac7e02b3f --- /dev/null +++ b/pkg/app2/log.go @@ -0,0 +1,49 @@ +package app2 + +import ( + "io" + "os" + "time" + + "github.com/skycoin/skycoin/src/util/logging" +) + +// NewLogger returns a logger which persists app logs. This logger should be passed down +// for use on any other function used by the app. It's configured from an additional app argument. +// It modifies os.Args stripping from it such value. Should be called before using os.Args inside the app +func NewLogger(appName string) *logging.MasterLogger { + db, err := newBoltDB(os.Args[1], appName) + if err != nil { + panic(err) + } + + l := newAppLogger() + l.SetOutput(io.MultiWriter(l.Out, db)) + os.Args = append([]string{os.Args[0]}, os.Args[2:]...) + + return l +} + +// TimestampFromLog is an utility function for retrieving the timestamp from a log. This function should be modified +// if the time layout is changed +func TimestampFromLog(log string) string { + return log[1:36] +} + +func (a *App) newPersistentLogger(path string) (*logging.MasterLogger, LogStore, error) { + db, err := newBoltDB(path, a.config.AppName) + if err != nil { + return nil, nil, err + } + + l := newAppLogger() + l.SetOutput(io.MultiWriter(l.Out, db)) + + return l, db, nil +} + +func newAppLogger() *logging.MasterLogger { + l := logging.NewMasterLogger() + l.Logger.Formatter.(*logging.TextFormatter).TimestampFormat = time.RFC3339Nano + return l +} diff --git a/pkg/app2/log_store.go b/pkg/app2/log_store.go new file mode 100644 index 000000000..d34d79074 --- /dev/null +++ b/pkg/app2/log_store.go @@ -0,0 +1,167 @@ +package app2 + +import ( + "bytes" + "fmt" + "io" + "strings" + "time" + + "go.etcd.io/bbolt" +) + +// LogStore stores logs from apps, for later consumption from the hypervisor +type LogStore interface { + // Write implements io.Writer + Write(p []byte) (n int, err error) + + // Store saves given log in db + Store(t time.Time, s string) error + + // LogSince returns the logs since given timestamp. For optimal performance, + // the timestamp should exist in the store (you can get it from previous logs), + // otherwise the DB will be sequentially iterated until finding entries older than given timestamp + LogsSince(t time.Time) ([]string, error) +} + +// NewLogStore returns a LogStore with path and app name of the given kind +func NewLogStore(path, appName, kind string) (LogStore, error) { + switch kind { + case "bbolt": + return newBoltDB(path, appName) + default: + return nil, fmt.Errorf("no LogStore of type %s", kind) + } +} + +type boltDBappLogs struct { + dbpath string + bucket []byte +} + +func newBoltDB(path, appName string) (_ LogStore, err error) { + db, err := bbolt.Open(path, 0600, nil) + if err != nil { + return nil, err + } + defer func() { + cErr := db.Close() + err = cErr + }() + + b := []byte(appName) + err = db.Update(func(tx *bbolt.Tx) error { + if _, err := tx.CreateBucketIfNotExists(b); err != nil { + return fmt.Errorf("failed to create bucket: %s", err) + } + + return nil + }) + if err != nil && !strings.Contains(err.Error(), bbolt.ErrBucketExists.Error()) { + return nil, err + } + + return &boltDBappLogs{path, b}, nil +} + +// Write implements io.Writer +func (l *boltDBappLogs) Write(p []byte) (int, error) { + // ensure there is at least timestamp long bytes + if len(p) < 37 { + return 0, io.ErrShortBuffer + } + + db, err := bbolt.Open(l.dbpath, 0600, nil) + if err != nil { + return 0, err + } + defer func() { + err := db.Close() + if err != nil { + panic(err) + } + }() + + // time in RFC3339Nano is between the bytes 1 and 36. This will change if other time layout is in use + t := p[1:36] + + err = db.Update(func(tx *bbolt.Tx) error { + b := tx.Bucket(l.bucket) + return b.Put(t, p) + }) + + if err != nil { + return 0, err + } + + return len(p), nil +} + +// Store implements LogStore +func (l *boltDBappLogs) Store(t time.Time, s string) (err error) { + db, err := bbolt.Open(l.dbpath, 0600, nil) + if err != nil { + return err + } + defer func() { + cErr := db.Close() + err = cErr + }() + + parsedTime := []byte(t.Format(time.RFC3339Nano)) + return db.Update(func(tx *bbolt.Tx) error { + b := tx.Bucket(l.bucket) + return b.Put(parsedTime, []byte(s)) + }) +} + +// LogSince implements LogStore +func (l *boltDBappLogs) LogsSince(t time.Time) (logs []string, err error) { + db, err := bbolt.Open(l.dbpath, 0600, nil) + if err != nil { + return nil, err + } + defer func() { + cErr := db.Close() + err = cErr + }() + + logs = make([]string, 0) + + err = db.View(func(tx *bbolt.Tx) error { + b := tx.Bucket(l.bucket) + parsedTime := []byte(t.Format(time.RFC3339Nano)) + c := b.Cursor() + + v := b.Get(parsedTime) + if v == nil { + logs = iterateFromBeginning(c, parsedTime) + return nil + } + c.Seek(parsedTime) + logs = iterateFromKey(c) + return nil + }) + + return logs, err +} + +func iterateFromKey(c *bbolt.Cursor) []string { + logs := make([]string, 0) + for k, v := c.Next(); k != nil; k, v = c.Next() { + logs = append(logs, string(v)) + } + return logs +} + +func iterateFromBeginning(c *bbolt.Cursor, parsedTime []byte) []string { + logs := make([]string, 0) + for k, v := c.First(); k != nil; k, v = c.Next() { + if bytes.Compare(k, parsedTime) < 0 { + continue + } + logs = append(logs, string(v)) + } + + return logs +} diff --git a/pkg/app2/log_store_test.go b/pkg/app2/log_store_test.go new file mode 100644 index 000000000..d8cba2977 --- /dev/null +++ b/pkg/app2/log_store_test.go @@ -0,0 +1,56 @@ +package app2 + +import ( + "fmt" + "io/ioutil" + "os" + "testing" + "time" + + "github.com/stretchr/testify/require" +) + +func TestLogStore(t *testing.T) { + p, err := ioutil.TempFile("", "test-db") + require.NoError(t, err) + + defer os.Remove(p.Name()) // nolint + + ls, err := newBoltDB(p.Name(), "foo") + require.NoError(t, err) + + t3, err := time.Parse(time.RFC3339, "2000-03-01T00:00:00Z") + require.NoError(t, err) + + err = ls.Store(t3, "foo") + require.NoError(t, err) + + t1, err := time.Parse(time.RFC3339, "2000-01-01T00:00:00Z") + require.NoError(t, err) + + err = ls.Store(t1, "bar") + fmt.Println("original: ", t1.Format(time.RFC3339Nano)) + require.NoError(t, err) + + t2, err := time.Parse(time.RFC3339, "2000-02-01T00:00:00Z") + require.NoError(t, err) + + err = ls.Store(t2, "middle") + require.NoError(t, err) + + res, err := ls.LogsSince(t1) + require.NoError(t, err) + require.Len(t, res, 2) + require.Contains(t, res[0], "middle") + require.Contains(t, res[1], "foo") + + t4, err := time.Parse(time.RFC3339, "1999-02-01T00:00:00Z") + require.NoError(t, err) + res, err = ls.LogsSince(t4) + require.NoError(t, err) + require.Len(t, res, 3) + require.Contains(t, res[0], "bar") + fmt.Println("b_ :", res[0]) + require.Contains(t, res[1], "middle") + require.Contains(t, res[2], "foo") +} diff --git a/pkg/app2/log_test.go b/pkg/app2/log_test.go new file mode 100644 index 000000000..d84525503 --- /dev/null +++ b/pkg/app2/log_test.go @@ -0,0 +1,38 @@ +package app2 + +import ( + "io/ioutil" + "os" + "testing" + "time" + + "github.com/stretchr/testify/require" +) + +// TestNewLogger tests that after the new logger is created logs with it are persisted into storage +func TestNewLogger(t *testing.T) { + p, err := ioutil.TempFile("", "test-db") + require.NoError(t, err) + + defer os.Remove(p.Name()) // nolint + + a := &App{ + config: Config{ + AppName: "foo", + }, + } + + l, _, err := a.newPersistentLogger(p.Name()) + require.NoError(t, err) + + dbl, err := newBoltDB(p.Name(), a.config.AppName) + require.NoError(t, err) + + l.Info("bar") + + beginning := time.Unix(0, 0) + res, err := dbl.(*boltDBappLogs).LogsSince(beginning) + require.NoError(t, err) + require.Len(t, res, 1) + require.Contains(t, res[0], "bar") +}