Improve debug logging throughout codebase

db/create.go

@@ -16,6 +16,7 @@ package db
 
 import (
 	"fmt"
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 	"github.com/abcum/surreal/util/item"
 	"github.com/abcum/surreal/util/keys"
@@ -24,6 +25,11 @@ import (
 
 func (e *executor) executeCreateStatement(ast *sql.CreateStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	for k, w := range ast.What {
 		if what, ok := w.(*sql.Param); ok {
 			ast.What[k] = e.ctx.Get(what.ID).Data()

db/db.go

@@ -253,11 +253,17 @@ func (e *executor) execute(quit <-chan bool, send chan<- *Response) {
 
 	defer func() {
 		if r := recover(); r != nil {
-			if err, ok := r.(error); ok {
+			switch err := r.(type) {
+			case string:
 				log.WithPrefix("db").Errorln(err)
 				if log.Instance().Level >= log.DebugLevel {
 					log.WithPrefix("db").Debugf("%s", debug.Stack())
 				}
+			case error:
+				log.WithPrefix("db").Errorln(err)
+				if log.Instance().Level >= log.DebugLevel {
+					log.WithPrefix("db").WithError(err).Debugf("%s", debug.Stack())
+				}
 			}
 		}
 	}()

db/define.go

@@ -15,6 +15,7 @@
 package db
 
 import (
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 	"github.com/abcum/surreal/util/item"
 	"github.com/abcum/surreal/util/keys"
@@ -23,6 +24,11 @@ import (
 
 func (e *executor) executeDefineNamespaceStatement(ast *sql.DefineNamespaceStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	// Set the namespace
 	nkey := &keys.NS{KV: ast.KV, NS: ast.Name}
 	_, err = e.txn.Put(0, nkey.Encode(), ast.Encode())
@@ -33,6 +39,11 @@ func (e *executor) executeDefineNamespaceStatement(ast *sql.DefineNamespaceState
 
 func (e *executor) executeDefineDatabaseStatement(ast *sql.DefineDatabaseStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	// Set the namespace
 	nkey := &keys.NS{KV: ast.KV, NS: ast.NS}
 	nval := &sql.DefineNamespaceStatement{Name: ast.NS}
@@ -48,6 +59,11 @@ func (e *executor) executeDefineDatabaseStatement(ast *sql.DefineDatabaseStateme
 
 func (e *executor) executeDefineLoginStatement(ast *sql.DefineLoginStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	if ast.Kind == sql.NAMESPACE {
 
 		// Set the namespace
@@ -85,6 +101,11 @@ func (e *executor) executeDefineLoginStatement(ast *sql.DefineLoginStatement) (o
 
 func (e *executor) executeDefineTokenStatement(ast *sql.DefineTokenStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	if ast.Kind == sql.NAMESPACE {
 
 		// Set the namespace
@@ -122,6 +143,11 @@ func (e *executor) executeDefineTokenStatement(ast *sql.DefineTokenStatement) (o
 
 func (e *executor) executeDefineScopeStatement(ast *sql.DefineScopeStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	// Set the namespace
 	nkey := &keys.NS{KV: ast.KV, NS: ast.NS}
 	nval := &sql.DefineNamespaceStatement{Name: ast.NS}
@@ -142,6 +168,11 @@ func (e *executor) executeDefineScopeStatement(ast *sql.DefineScopeStatement) (o
 
 func (e *executor) executeDefineTableStatement(ast *sql.DefineTableStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	// Set the namespace
 	nkey := &keys.NS{KV: ast.KV, NS: ast.NS}
 	nval := &sql.DefineNamespaceStatement{Name: ast.NS}
@@ -168,6 +199,11 @@ func (e *executor) executeDefineTableStatement(ast *sql.DefineTableStatement) (o
 
 func (e *executor) executeDefineFieldStatement(ast *sql.DefineFieldStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	// Set the namespace
 	nkey := &keys.NS{KV: ast.KV, NS: ast.NS}
 	nval := &sql.DefineNamespaceStatement{Name: ast.NS}
@@ -199,6 +235,11 @@ func (e *executor) executeDefineFieldStatement(ast *sql.DefineFieldStatement) (o
 
 func (e *executor) executeDefineIndexStatement(ast *sql.DefineIndexStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	// Set the namespace
 	nkey := &keys.NS{KV: ast.KV, NS: ast.NS}
 	nval := &sql.DefineNamespaceStatement{Name: ast.NS}

db/delete.go

@@ -16,6 +16,7 @@ package db
 
 import (
 	"fmt"
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 	"github.com/abcum/surreal/util/item"
 	"github.com/abcum/surreal/util/keys"
@@ -23,6 +24,11 @@ import (
 
 func (e *executor) executeDeleteStatement(ast *sql.DeleteStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	for k, w := range ast.What {
 		if what, ok := w.(*sql.Param); ok {
 			ast.What[k] = e.ctx.Get(what.ID).Data()

db/info.go

@@ -15,12 +15,18 @@
 package db
 
 import (
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 	"github.com/abcum/surreal/util/data"
 )
 
 func (e *executor) executeInfoStatement(ast *sql.InfoStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	switch ast.Kind {
 	case sql.NAMESPACE:
 		return e.executeInfoNSStatement(ast)

db/let.go

@@ -15,11 +15,17 @@
 package db
 
 import (
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 )
 
 func (e *executor) executeLetStatement(ast *sql.LetStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	switch what := ast.What.(type) {
 	default:
 		e.Set(ast.Name, what)

db/relate.go

@@ -15,9 +15,17 @@
 package db
 
 import (
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 )
 
 func (e *executor) executeRelateStatement(ast *sql.RelateStatement) (out []interface{}, err error) {
+
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	return nil, nil
+
 }

db/remove.go

@@ -15,12 +15,18 @@
 package db
 
 import (
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 	"github.com/abcum/surreal/util/keys"
 )
 
 func (e *executor) executeRemoveNamespaceStatement(ast *sql.RemoveNamespaceStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	// Remove the namespace
 	nkey := &keys.NS{KV: ast.KV, NS: ast.Name}
 	_, err = e.txn.DelP(0, nkey.Encode(), 0)
@@ -31,6 +37,11 @@ func (e *executor) executeRemoveNamespaceStatement(ast *sql.RemoveNamespaceState
 
 func (e *executor) executeRemoveDatabaseStatement(ast *sql.RemoveDatabaseStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	// Remove the database
 	dkey := &keys.DB{KV: ast.KV, NS: ast.NS, DB: ast.Name}
 	_, err = e.txn.DelP(0, dkey.Encode(), 0)
@@ -41,6 +52,11 @@ func (e *executor) executeRemoveDatabaseStatement(ast *sql.RemoveDatabaseStateme
 
 func (e *executor) executeRemoveLoginStatement(ast *sql.RemoveLoginStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	if ast.Kind == sql.NAMESPACE {
 
 		// Remove the login
@@ -63,6 +79,11 @@ func (e *executor) executeRemoveLoginStatement(ast *sql.RemoveLoginStatement) (o
 
 func (e *executor) executeRemoveTokenStatement(ast *sql.RemoveTokenStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	if ast.Kind == sql.NAMESPACE {
 
 		// Remove the token
@@ -85,6 +106,11 @@ func (e *executor) executeRemoveTokenStatement(ast *sql.RemoveTokenStatement) (o
 
 func (e *executor) executeRemoveScopeStatement(ast *sql.RemoveScopeStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	// Remove the scope
 	skey := &keys.SC{KV: ast.KV, NS: ast.NS, DB: ast.DB, SC: ast.Name}
 	_, err = e.txn.DelP(0, skey.Encode(), 0)
@@ -95,6 +121,11 @@ func (e *executor) executeRemoveScopeStatement(ast *sql.RemoveScopeStatement) (o
 
 func (e *executor) executeRemoveTableStatement(ast *sql.RemoveTableStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	for _, TB := range ast.What {
 
 		// Remove the table
@@ -109,6 +140,11 @@ func (e *executor) executeRemoveTableStatement(ast *sql.RemoveTableStatement) (o
 
 func (e *executor) executeRemoveFieldStatement(ast *sql.RemoveFieldStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	for _, TB := range ast.What {
 
 		// Remove the field
@@ -123,6 +159,11 @@ func (e *executor) executeRemoveFieldStatement(ast *sql.RemoveFieldStatement) (o
 
 func (e *executor) executeRemoveIndexStatement(ast *sql.RemoveIndexStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	for _, TB := range ast.What {
 
 		// Remove the index

db/return.go

@@ -15,11 +15,17 @@
 package db
 
 import (
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 )
 
 func (e *executor) executeReturnStatement(ast *sql.ReturnStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	switch what := ast.What.(type) {
 	default:
 		out = append(out, what)

db/select.go

@@ -15,6 +15,7 @@
 package db
 
 import (
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 	"github.com/abcum/surreal/util/item"
 	"github.com/abcum/surreal/util/keys"
@@ -22,6 +23,11 @@ import (
 
 func (e *executor) executeSelectStatement(ast *sql.SelectStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	for k, w := range ast.What {
 		if what, ok := w.(*sql.Param); ok {
 			ast.What[k] = e.ctx.Get(what.ID).Data()

db/update.go

@@ -16,6 +16,7 @@ package db
 
 import (
 	"fmt"
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/sql"
 	"github.com/abcum/surreal/util/item"
 	"github.com/abcum/surreal/util/keys"
@@ -23,6 +24,11 @@ import (
 
 func (e *executor) executeUpdateStatement(ast *sql.UpdateStatement) (out []interface{}, err error) {
 
+	log.WithPrefix("sql").WithFields(map[string]interface{}{
+		"ns": ast.NS,
+		"db": ast.DB,
+	}).Debugln(ast)
+
 	for k, w := range ast.What {
 		if what, ok := w.(*sql.Param); ok {
 			ast.What[k] = e.ctx.Get(what.ID).Data()

web/signin.go

@@ -20,6 +20,7 @@ import (
 	"github.com/abcum/fibre"
 	"github.com/abcum/surreal/db"
 	"github.com/abcum/surreal/kvs"
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/mem"
 	"github.com/abcum/surreal/sql"
 
@@ -61,17 +62,39 @@ func signin(c *fibre.Context) (err error) {
 		// Get the specified signin scope.
 
 		if scp, err = mem.New(txn).GetSC(n, d, s); err != nil {
+			log.WithFields(map[string]interface{}{
+				"ns":  n,
+				"db":  d,
+				"sc":  s,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Authentication scope does not exist")
 			return fibre.NewHTTPError(403)
 		}
 
 		// Process the scope signin statement.
 
-		res, err = db.Process(c, &sql.Query{Statements: []sql.Statement{scp.Signin}}, vars)
-		if err != nil {
-			return fibre.NewHTTPError(403)
+		qury := &sql.Query{Statements: []sql.Statement{scp.Signup}}
+
+		if res, err = db.Process(c, qury, vars); err != nil {
+			log.WithFields(map[string]interface{}{
+				"ns":  n,
+				"db":  d,
+				"sc":  s,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Authentication scope signin was unsuccessful")
+			return fibre.NewHTTPError(501)
 		}
 
 		if len(res) != 1 && len(res[0].Result) != 1 {
+			log.WithFields(map[string]interface{}{
+				"ns":  n,
+				"db":  d,
+				"sc":  s,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Authentication scope signin was unsuccessful")
 			return fibre.NewHTTPError(403)
 		}
 
@@ -93,9 +116,24 @@ func signin(c *fibre.Context) (err error) {
 
 		str, err = signr.SignedString(scp.Code)
 		if err != nil {
+			log.WithFields(map[string]interface{}{
+				"ns":  n,
+				"db":  d,
+				"sc":  s,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Problem with signing string")
 			return fibre.NewHTTPError(403)
 		}
 
+		log.WithFields(map[string]interface{}{
+			"ns":  n,
+			"db":  d,
+			"sc":  s,
+			"url": "/signin",
+			"id":  c.Get("id"),
+		}).Debugln("Authentication scope signin was successful")
+
 		return c.Text(200, str)
 
 	}
@@ -116,6 +154,12 @@ func signin(c *fibre.Context) (err error) {
 		p, pok := vars["pass"].(string)
 
 		if !uok || len(u) == 0 || !pok || len(p) == 0 {
+			log.WithPrefix("web").WithFields(map[string]interface{}{
+				"ns":  n,
+				"nu":  u,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Username or password is missing")
 			return fibre.NewHTTPError(403)
 		}
 
@@ -133,6 +177,13 @@ func signin(c *fibre.Context) (err error) {
 		// Get the specified database login.
 
 		if usr, err = mem.New(txn).GetDU(n, d, u); err != nil {
+			log.WithFields(map[string]interface{}{
+				"ns":  n,
+				"db":  d,
+				"du":  u,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Database login does not exist")
 			return fibre.NewHTTPError(403)
 		}
 
@@ -140,6 +191,13 @@ func signin(c *fibre.Context) (err error) {
 
 		err = bcrypt.CompareHashAndPassword(usr.Pass, []byte(p))
 		if err != nil {
+			log.WithFields(map[string]interface{}{
+				"ns":  n,
+				"db":  d,
+				"du":  u,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Database signin was unsuccessful")
 			return fibre.NewHTTPError(403)
 		}
 
@@ -160,9 +218,24 @@ func signin(c *fibre.Context) (err error) {
 
 		str, err = signr.SignedString(usr.Code)
 		if err != nil {
+			log.WithFields(map[string]interface{}{
+				"ns":  n,
+				"db":  d,
+				"du":  u,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Problem with signing string")
 			return fibre.NewHTTPError(403)
 		}
 
+		log.WithFields(map[string]interface{}{
+			"ns":  n,
+			"db":  d,
+			"du":  u,
+			"url": "/signin",
+			"id":  c.Get("id"),
+		}).Debugln("Database signin was successful")
+
 		return c.Text(200, str)
 
 	}
@@ -183,6 +256,12 @@ func signin(c *fibre.Context) (err error) {
 		p, pok := vars["pass"].(string)
 
 		if !uok || len(u) == 0 || !pok || len(p) == 0 {
+			log.WithPrefix("web").WithFields(map[string]interface{}{
+				"ns":  n,
+				"nu":  u,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Username or password is missing")
 			return fibre.NewHTTPError(403)
 		}
 
@@ -199,6 +278,12 @@ func signin(c *fibre.Context) (err error) {
 		// Get the specified namespace login.
 
 		if usr, err = mem.New(txn).GetNU(n, u); err != nil {
+			log.WithPrefix("web").WithFields(map[string]interface{}{
+				"ns":  n,
+				"nu":  u,
+				"url": "/signin",
+				"id":  c.Get("id"),
+			}).Debugln("Namespace login does not exist")
 			return fibre.NewHTTPError(403)
 		}
 
@@ -206,6 +291,11 @@ func signin(c *fibre.Context) (err error) {
 
 		err = bcrypt.CompareHashAndPassword(usr.Pass, []byte(p))
 		if err != nil {
+			log.WithPrefix("web").WithFields(map[string]interface{}{
+				"NS":  n,
+				"NU":  u,
+				"URL": "/signin",
+			}).Debugln("Namespace signin was unsuccessful")
 			return fibre.NewHTTPError(403)
 		}
 
@@ -225,9 +315,21 @@ func signin(c *fibre.Context) (err error) {
 
 		str, err = signr.SignedString(usr.Code)
 		if err != nil {
+			log.WithPrefix("web").WithFields(map[string]interface{}{
+				"NS":  n,
+				"NU":  u,
+				"URL": "/signin",
+			}).Debugln("Problem with signing string")
 			return fibre.NewHTTPError(403)
 		}
 
+		log.WithFields(map[string]interface{}{
+			"ns":  n,
+			"du":  u,
+			"url": "/signin",
+			"id":  c.Get("id"),
+		}).Debugln("Namespace signin was successful")
+
 		return c.Text(200, str)
 
 	}

web/signup.go

@@ -18,6 +18,7 @@ import (
 	"github.com/abcum/fibre"
 	"github.com/abcum/surreal/db"
 	"github.com/abcum/surreal/kvs"
+	"github.com/abcum/surreal/log"
 	"github.com/abcum/surreal/mem"
 	"github.com/abcum/surreal/sql"
 )
@@ -55,17 +56,36 @@ func signup(c *fibre.Context) (err error) {
 		// Get the specified signin scope.
 
 		if scp, err = mem.New(txn).GetSC(n, d, s); err != nil {
+			log.WithFields(map[string]interface{}{
+				"NS":  n,
+				"DB":  d,
+				"SC":  s,
+				"url": "/signup",
+			}).Debugln("Authentication scope does not exist")
 			return fibre.NewHTTPError(403)
 		}
 
 		// Process the scope signup statement.
 
-		res, err = db.Process(c, &sql.Query{Statements: []sql.Statement{scp.Signup}}, vars)
-		if err != nil {
-			return fibre.NewHTTPError(403)
+		qury := &sql.Query{Statements: []sql.Statement{scp.Signup}}
+
+		if res, err = db.Process(c, qury, vars); err != nil {
+			log.WithFields(map[string]interface{}{
+				"NS":  n,
+				"DB":  d,
+				"SC":  s,
+				"URL": "/signup",
+			}).Debugln("Authentication scope signup was unsuccessful")
+			return fibre.NewHTTPError(501)
 		}
 
 		if len(res) != 1 && len(res[0].Result) != 1 {
+			log.WithFields(map[string]interface{}{
+				"NS":  n,
+				"DB":  d,
+				"SC":  s,
+				"URL": "/signup",
+			}).Debugln("Authentication scope signup was unsuccessful")
 			return fibre.NewHTTPError(403)
 		}