logs succesfully stored and hypervisor and cmd clients for it

cmd/apps/skychat/chat.go

@@ -11,12 +11,10 @@ import (
 	"fmt"
 	"net"
 	"net/http"
-	"os"
 	"sync"
 	"time"
 
 	"github.com/skycoin/dmsg/cipher"
-
 	"github.com/skycoin/skycoin/src/util/logging"
 
 	"github.com/skycoin/skywire/internal/netutil"
@@ -36,10 +34,10 @@ var (
 )
 
 func main() {
-	flag.Parse()
 	appName := "skychat"
-	fmt.Println(os.Args)
-	log, _ = app.NewLogger(appName, os.Args)
+	log = app.NewLogger(appName)
+	flag.Parse()
+
 	a, err := app.Setup(&app.Config{AppName: appName, AppVersion: "1.0", ProtocolVersion: "0.0.1"})
 	if err != nil {
 		log.Fatal("Setup failure: ", err)

cmd/skywire-cli/commands/node/app.go

@@ -19,6 +19,7 @@ func init() {
 		startAppCmd,
 		stopAppCmd,
 		setAppAutostartCmd,
+		appLogsSinceCmd,
 	)
 }
 
@@ -84,14 +85,21 @@ var setAppAutostartCmd = &cobra.Command{
 	},
 }
 
-var appLogsSince = &cobra.Command{
+var appLogsSinceCmd = &cobra.Command{
 	Use:   "app-logs-since <name> <timestamp>",
-	Short: "Gets logs from given app since RFC3339Nano-formated timestamp",
+	Short: "Gets logs from given app since RFC3339Nano-formated timestamp. \"beginning\" is a special timestamp to fetch all the logs",
 	Args:  cobra.MinimumNArgs(2),
 	Run: func(_ *cobra.Command, args []string) {
-		strTime := args[1]
-		t, err := time.Parse(time.RFC3339Nano, strTime)
-		internal.Catch(err)
+		var t time.Time
+
+		if args[1] == "beginning" {
+			t = time.Unix(0, 0)
+		} else {
+			var err error
+			strTime := args[1]
+			t, err = time.Parse(time.RFC3339Nano, strTime)
+			internal.Catch(err)
+		}
 		logs, err := rpcClient().LogsSince(t, args[0])
 		internal.Catch(err)
 		if len(logs) > 0 {

go.sum

@@ -136,6 +136,7 @@ golang.org/x/sys v0.0.0-20190626221950-04f50cda93cb/go.mod h1:h1NjWce9XRLGQEsW7w
 golang.org/x/sys v0.0.0-20190804053845-51ab0e2deafa h1:KIDDMLT1O0Nr7TSxp8xM5tJcdn8tgyAONntO829og1M=
 golang.org/x/sys v0.0.0-20190804053845-51ab0e2deafa/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
+golang.org/x/text v0.3.2 h1:tW2bmiBqwgJj/UpqtC8EpXEZVYOwU0yG4iWbprSVAcs=
 golang.org/x/text v0.3.2/go.mod h1:bEr9sfX3Q8Zfm5fL9x+3itogRgK3+ptLWKqgva+5dAk=
 golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
 golang.org/x/tools v0.0.0-20190627182818-9947fec5c3ab/go.mod h1:/rFqwRUd4F7ZHNgwSSTFct+R/Kf4OFW1sUzUTQQTgfc=

pkg/app/log.go

@@ -2,35 +2,32 @@ package app
 
 import (
 	"io"
+	"os"
 	"time"
 
 	"github.com/skycoin/skycoin/src/util/logging"
 )
 
-// NewLogger is like (a *App) LoggerFromArguments but with appName as parameter, instead of
-// getting it from app config
-func NewLogger(appName string, args []string) (*logging.MasterLogger, []string) {
-	db, err := newBoltDB(args[1], appName)
+// 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, append([]string{args[0]}, args[2:]...)
+	return l
 }
 
-// LoggerFromArguments 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 also returns the args list with such argument stripped from it, for convenience
-func (a *App) LoggerFromArguments(args []string) (*logging.MasterLogger, []string) {
-	l, _, err := a.newPersistentLogger(args[1])
-	if err != nil {
-		panic(err)
-	}
-
-	return l, append([]string{args[0]}, args[2:]...)
+// 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) {

pkg/app/log_store.go

@@ -34,7 +34,7 @@ func NewLogStore(path, appName, kind string) (LogStore, error) {
 }
 
 type boltDBappLogs struct {
-	db     *bbolt.DB
+	dbpath string
 	bucket []byte
 }
 
@@ -43,6 +43,12 @@ func newBoltDB(path, appName string) (LogStore, error) {
 	if err != nil {
 		return nil, err
 	}
+	defer func() {
+		err := db.Close()
+		if err != nil {
+			panic(err)
+		}
+	}()
 
 	b := []byte(appName)
 	err = db.Update(func(tx *bbolt.Tx) error {
@@ -56,15 +62,26 @@ func newBoltDB(path, appName string) (LogStore, error) {
 		return nil, err
 	}
 
-	return &boltDBappLogs{db, b}, nil
+	return &boltDBappLogs{path, b}, nil
 }
 
 // Write implements io.Writer
 func (l *boltDBappLogs) Write(p []byte) (int, error) {
+	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 := l.db.Update(func(tx *bbolt.Tx) error {
+	err = db.Update(func(tx *bbolt.Tx) error {
 		b := tx.Bucket(l.bucket)
 		return b.Put(t, p)
 	})
@@ -78,18 +95,40 @@ func (l *boltDBappLogs) Write(p []byte) (int, error) {
 
 // Store implements LogStore
 func (l *boltDBappLogs) Store(t time.Time, s string) error {
+	db, err := bbolt.Open(l.dbpath, 0600, nil)
+	if err != nil {
+		return err
+	}
+	defer func() {
+		err := db.Close()
+		if err != nil {
+			panic(err)
+		}
+	}()
+
 	parsedTime := []byte(t.Format(time.RFC3339Nano))
-	return l.db.Update(func(tx *bbolt.Tx) error {
+	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) ([]string, error) {
+	db, err := bbolt.Open(l.dbpath, 0600, nil)
+	if err != nil {
+		return nil, err
+	}
+	defer func() {
+		err := db.Close()
+		if err != nil {
+			panic(err)
+		}
+	}()
+
 	logs := make([]string, 0)
 
-	err := l.db.View(func(tx *bbolt.Tx) error {
+	err = db.View(func(tx *bbolt.Tx) error {
 		b := tx.Bucket(l.bucket)
 		parsedTime := []byte(t.Format(time.RFC3339Nano))
 		c := b.Cursor()
@@ -107,12 +146,7 @@ func (l *boltDBappLogs) LogsSince(t time.Time) ([]string, error) {
 
 func iterateFromKey(c *bbolt.Cursor, logs *[]string) error {
 	for k, v := c.Next(); k != nil; k, v = c.Next() {
-		t, err := bytesToTime(k)
-		if err != nil {
-
-			return err
-		}
-		*logs = append(*logs, fmt.Sprintf("%s-%s", t.Format(time.RFC3339Nano), string(v)))
+		*logs = append(*logs, string(v))
 	}
 	return nil
 }
@@ -122,11 +156,7 @@ func iterateFromBeginning(c *bbolt.Cursor, parsedTime []byte, logs *[]string) er
 		if bytes.Compare(k, parsedTime) < 0 {
 			continue
 		}
-		t, err := bytesToTime(k)
-		if err != nil {
-			return err
-		}
-		*logs = append(*logs, t.Format(time.RFC3339Nano), string(v))
+		*logs = append(*logs, string(v))
 	}
 
 	return nil

pkg/app/log_store_test.go

@@ -2,11 +2,10 @@ package app
 
 import (
 	"fmt"
-	"os"
-	"time"
-
 	"io/ioutil"
+	"os"
 	"testing"
+	"time"
 
 	"github.com/stretchr/testify/require"
 )

pkg/app/log_test.go

@@ -1,44 +1,15 @@
 package app
 
 import (
-	"fmt"
-	"io"
 	"io/ioutil"
 	"os"
 	"testing"
 	"time"
 
-	"github.com/skycoin/skycoin/src/util/logging"
 	"github.com/stretchr/testify/require"
 )
 
-func TestWriteLog(t *testing.T) {
-	r, w := io.Pipe()
-
-	l := logging.NewMasterLogger()
-	l.SetOutput(w)
-	l.Logger.Formatter.(*logging.TextFormatter).TimestampFormat = time.RFC3339Nano
-	c := make(chan []byte)
-
-	go func() {
-		b := make([]byte, 51)
-		r.Read(b)
-		c <- b
-	}()
-	l.Println("foo")
-
-	res := <-c
-	ti := res[1:36]
-
-	pt, err := time.Parse(time.RFC3339Nano, string(ti))
-	if err != nil {
-		t.Fail()
-	}
-
-	fmt.Println("t in unix nano", pt.UnixNano())
-	fmt.Printf("%#v", string(res))
-}
-
+// 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)
@@ -59,14 +30,9 @@ func TestNewLogger(t *testing.T) {
 
 	l.Info("bar")
 
-	// here we parse the layout itself since it's a date from 2006, so it is earlier than any other logs produced now.
-	// The last 5 characters are extracted since otherwise it cannot be parsed
-	beggining, err := time.Parse(time.RFC3339Nano, time.RFC3339Nano[:len(time.RFC3339Nano)-5])
-	require.NoError(t, err)
+	beggining := time.Unix(0, 0)
 	res, err := dbl.(*boltDBappLogs).LogsSince(beggining)
 	require.NoError(t, err)
 	require.Len(t, res, 1)
-	fmt.Println("from db: ", res[0])
-	fmt.Println(time.Now().Format(time.RFC3339Nano))
 	require.Contains(t, res[0], "bar")
 }