Add old app logger

cmd/apps/skychat/chat.go

@@ -14,19 +14,20 @@ 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"
 )
 
 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

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
+}

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
+}

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")
+}

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")
+}