From a700ef9bc4fc0abd6184424acba183cd6fd17920 Mon Sep 17 00:00:00 2001 From: Tobie Morgan Hitchcock Date: Mon, 20 Feb 2017 01:11:50 +0000 Subject: [PATCH] Improve debug logging throughout codebase --- db/create.go | 6 +++ db/db.go | 8 +++- db/define.go | 41 +++++++++++++++++++ db/delete.go | 6 +++ db/info.go | 6 +++ db/let.go | 6 +++ db/relate.go | 8 ++++ db/remove.go | 41 +++++++++++++++++++ db/return.go | 6 +++ db/select.go | 6 +++ db/update.go | 6 +++ web/signin.go | 108 ++++++++++++++++++++++++++++++++++++++++++++++++-- web/signup.go | 26 ++++++++++-- 13 files changed, 267 insertions(+), 7 deletions(-) diff --git a/db/create.go b/db/create.go index 5632cc0f..cdd3697c 100644 --- a/db/create.go +++ b/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() diff --git a/db/db.go b/db/db.go index bf26cb5f..aa24191b 100644 --- a/db/db.go +++ b/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()) + } } } }() diff --git a/db/define.go b/db/define.go index b77b072c..f3ff0e3d 100644 --- a/db/define.go +++ b/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} diff --git a/db/delete.go b/db/delete.go index 59d2bfab..37f77179 100644 --- a/db/delete.go +++ b/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() diff --git a/db/info.go b/db/info.go index b96c85bf..94a5b661 100644 --- a/db/info.go +++ b/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) diff --git a/db/let.go b/db/let.go index 6e757c81..b9ecde3f 100644 --- a/db/let.go +++ b/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) diff --git a/db/relate.go b/db/relate.go index e375ed06..17531a00 100644 --- a/db/relate.go +++ b/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 + } diff --git a/db/remove.go b/db/remove.go index ce8f026f..fc31a32a 100644 --- a/db/remove.go +++ b/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 diff --git a/db/return.go b/db/return.go index 0bebe3d9..6d75d747 100644 --- a/db/return.go +++ b/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) diff --git a/db/select.go b/db/select.go index 13f5e41a..eb51356c 100644 --- a/db/select.go +++ b/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() diff --git a/db/update.go b/db/update.go index 99dde54a..49e5434d 100644 --- a/db/update.go +++ b/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() diff --git a/web/signin.go b/web/signin.go index ddd10852..96b7c361 100644 --- a/web/signin.go +++ b/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) } diff --git a/web/signup.go b/web/signup.go index 5e9eebc2..6068f06e 100644 --- a/web/signup.go +++ b/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) }