diff --git a/config.go b/config.go new file mode 100644 index 0000000000000000000000000000000000000000..4c4134e9bf61cce88844c7e4487bfcd255b753e0 --- /dev/null +++ b/config.go @@ -0,0 +1,38 @@ +package db + +import ( + "sync/atomic" +) + +type config struct { + loggingEnabled uint32 + queryLogger atomic.Value +} + +func (c *config) Logger() Logger { + if lg := c.queryLogger.Load(); lg != nil { + return lg.(Logger) + } + return nil +} + +func (c *config) SetLogger(lg Logger) { + c.queryLogger.Store(lg) +} + +func (c *config) SetLogging(value bool) { + if value { + atomic.StoreUint32(&c.loggingEnabled, 1) + return + } + atomic.StoreUint32(&c.loggingEnabled, 0) +} + +func (c *config) LoggingEnabled() bool { + if v := atomic.LoadUint32(&c.loggingEnabled); v == 1 { + return true + } + return false +} + +var Config = config{} diff --git a/db.go b/db.go index 56e2285328ab3ecbd4f880870585e71e25dccae0..877c300d4e7944115697da0ab3f94d4cfce95fb8 100644 --- a/db.go +++ b/db.go @@ -562,23 +562,6 @@ type ConnectionURL interface { String() string } -// EnvEnableDebug can be used by adapters to determine if the user has enabled -// debugging. -// -// If the user sets the `UPPERIO_DB_DEBUG` environment variable to a -// non-empty value, all generated statements will be printed at runtime to -// the standard logger. -// -// Example: -// -// UPPERIO_DB_DEBUG=1 go test -// -// UPPERIO_DB_DEBUG=1 ./go-program -const EnvEnableDebug = `UPPERIO_DB_DEBUG` - -// Debug is a variable that, when true, enables query printing. -var Debug = false - // Ensure interface compatibility var ( _ Function = &dbFunc{} diff --git a/env.go b/env.go new file mode 100644 index 0000000000000000000000000000000000000000..6ff0cd39ad4ac724a61d31ba6f0821a2bbe9c8a4 --- /dev/null +++ b/env.go @@ -0,0 +1,13 @@ +package db + +import ( + "os" +) + +func envEnabled(name string) bool { + switch os.Getenv(name) { + case "1", "true", "TRUE", "t", "T": + return true + } + return false +} diff --git a/internal/logger/logger.go b/internal/logger/logger.go deleted file mode 100644 index 8cacf196c8f925264f18a2a657b357903685e198..0000000000000000000000000000000000000000 --- a/internal/logger/logger.go +++ /dev/null @@ -1,82 +0,0 @@ -// Copyright (c) 2012-present The upper.io/db authors. All rights reserved. -// -// Permission is hereby granted, free of charge, to any person obtaining -// a copy of this software and associated documentation files (the -// "Software"), to deal in the Software without restriction, including -// without limitation the rights to use, copy, modify, merge, publish, -// distribute, sublicense, and/or sell copies of the Software, and to -// permit persons to whom the Software is furnished to do so, subject to -// the following conditions: -// -// The above copyright notice and this permission notice shall be -// included in all copies or substantial portions of the Software. -// -// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, -// EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF -// MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND -// NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE -// LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION -// OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION -// WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. - -package logger - -import ( - "fmt" - "log" - "os" - "regexp" - "strings" - - "upper.io/db.v2" -) - -var ( - reInvisibleChars = regexp.MustCompile(`[\s\r\n\t]+`) - reColumnCompareExclude = regexp.MustCompile(`[^a-zA-Z0-9]`) -) - -func init() { - if os.Getenv(db.EnvEnableDebug) != "" { - db.Debug = true - } -} - -type message struct { - Query string - Args []interface{} - Err error - Start int64 - End int64 -} - -func (m *message) Print() { - m.Query = reInvisibleChars.ReplaceAllString(m.Query, ` `) - m.Query = strings.TrimSpace(m.Query) - - s := make([]string, 0, 3) - - if m.Query != "" { - s = append(s, fmt.Sprintf(`Q: %s`, m.Query)) - } - - if len(m.Args) > 0 { - s = append(s, fmt.Sprintf(`A: %v`, m.Args)) - } - - if m.Err != nil { - s = append(s, fmt.Sprintf(`E: %q`, m.Err)) - } - - s = append(s, fmt.Sprintf(`T: %0.5fs`, float64(m.End-m.Start)/float64(1e9))) - - log.Printf("\n\t%s\n\n", strings.Join(s, "\n\t")) -} - -// Log prints the given query to stdout in readable format. -func Log(query string, args []interface{}, err error, start int64, end int64) { - if db.Debug { - m := message{query, args, err, start, end} - m.Print() - } -} diff --git a/internal/sqladapter/database.go b/internal/sqladapter/database.go index 27cf5b3f7d190da140091e817ca72416e7bf4ef4..ff76d904a63f12cd47e44df1f55e7c5dfc645c53 100644 --- a/internal/sqladapter/database.go +++ b/internal/sqladapter/database.go @@ -8,7 +8,6 @@ import ( "upper.io/db.v2" "upper.io/db.v2/internal/cache" - "upper.io/db.v2/internal/logger" "upper.io/db.v2/internal/sqladapter/exql" "upper.io/db.v2/lib/sqlbuilder" ) @@ -221,19 +220,21 @@ func (d *database) Collection(name string) db.Collection { // rows. func (d *database) StatementExec(stmt *exql.Statement, args ...interface{}) (sql.Result, error) { var query string - var p *sql.Stmt var err error - if db.Debug { - var start, end int64 - start = time.Now().UnixNano() - - defer func() { - end = time.Now().UnixNano() - logger.Log(query, args, err, start, end) - }() + if db.Config.LoggingEnabled() { + defer func(start time.Time) { + db.Log(&db.QueryStatus{ + Query: query, + Args: args, + Err: err, + Start: start, + End: time.Now(), + }) + }(time.Now()) } + var p *sql.Stmt if p, query, err = d.prepareStatement(stmt); err != nil { return nil, err } @@ -248,19 +249,21 @@ func (d *database) StatementExec(stmt *exql.Statement, args ...interface{}) (sql // StatementQuery compiles and executes a statement that returns rows. func (d *database) StatementQuery(stmt *exql.Statement, args ...interface{}) (*sql.Rows, error) { var query string - var p *sql.Stmt var err error - if db.Debug { - var start, end int64 - start = time.Now().UnixNano() - - defer func() { - end = time.Now().UnixNano() - logger.Log(query, args, err, start, end) - }() + if db.Config.LoggingEnabled() { + defer func(start time.Time) { + db.Log(&db.QueryStatus{ + Query: query, + Args: args, + Err: err, + Start: start, + End: time.Now(), + }) + }(time.Now()) } + var p *sql.Stmt if p, query, err = d.prepareStatement(stmt); err != nil { return nil, err } @@ -272,19 +275,21 @@ func (d *database) StatementQuery(stmt *exql.Statement, args ...interface{}) (*s // row. func (d *database) StatementQueryRow(stmt *exql.Statement, args ...interface{}) (*sql.Row, error) { var query string - var p *sql.Stmt var err error - if db.Debug { - var start, end int64 - start = time.Now().UnixNano() - - defer func() { - end = time.Now().UnixNano() - logger.Log(query, args, err, start, end) - }() + if db.Config.LoggingEnabled() { + defer func(start time.Time) { + db.Log(&db.QueryStatus{ + Query: query, + Args: args, + Err: err, + Start: start, + End: time.Now(), + }) + }(time.Now()) } + var p *sql.Stmt if p, query, err = d.prepareStatement(stmt); err != nil { return nil, err } diff --git a/logger.go b/logger.go new file mode 100644 index 0000000000000000000000000000000000000000..7b3885879d7286f7b7eb59ef23e4021f95941c95 --- /dev/null +++ b/logger.go @@ -0,0 +1,93 @@ +package db + +import ( + "fmt" + "log" + "regexp" + "strings" + "time" +) + +// QueryStatus represents a query after being executed. +type QueryStatus struct { + SessionID uint64 + TxID uint64 + + Query string + Args []interface{} + + Err error + + Start time.Time + End time.Time +} + +// EnvEnableDebug can be used by adapters to determine if the user has enabled +// debugging. +// +// If the user sets the `UPPERIO_DB_DEBUG` environment variable to a +// non-empty value, all generated statements will be printed at runtime to +// the standard logger. +// +// Example: +// +// UPPERIO_DB_DEBUG=1 go test +// +// UPPERIO_DB_DEBUG=1 ./go-program +const ( + EnvEnableDebug = `UPPERIO_DB_DEBUG` +) + +func init() { + if envEnabled(EnvEnableDebug) { + Config.SetLogger(&defaultLogger{}) // Using default logger. + Config.SetLogging(true) + } +} + +// Logger represents a logging collector. You can pass a logging collector to +// db.Config.SetLogger(myCollector) to make it collect db.QueryStatus messages +// after every query. +type Logger interface { + Log(*QueryStatus) +} + +// Log sends a query status report to the configured logger. +func Log(m *QueryStatus) { + if lg := Config.Logger(); lg != nil { + lg.Log(m) + return + } + log.Printf("No logger has been configured, use db.Config.SetLogger()") +} + +var ( + reInvisibleChars = regexp.MustCompile(`[\s\r\n\t]+`) + reColumnCompareExclude = regexp.MustCompile(`[^a-zA-Z0-9]`) +) + +type defaultLogger struct { +} + +func (lg *defaultLogger) Log(m *QueryStatus) { + m.Query = reInvisibleChars.ReplaceAllString(m.Query, ` `) + m.Query = strings.TrimSpace(m.Query) + + s := make([]string, 0, 4) + + if m.Query != "" { + s = append(s, fmt.Sprintf(`Q: %s`, m.Query)) + } + + if len(m.Args) > 0 { + s = append(s, fmt.Sprintf(`A: %#v`, m.Args)) + } + + if m.Err != nil { + s = append(s, fmt.Sprintf(`E: %q`, m.Err)) + } + + s = append(s, fmt.Sprintf(`T: %0.5fs`, float64(m.End.UnixNano()-m.Start.UnixNano())/float64(1e9))) + + log.Printf("\n\t%s\n\n", strings.Join(s, "\n\t")) +} diff --git a/mongo/result.go b/mongo/result.go index 0aeee6bdc4f3aad642db18766443953dd900dce4..0916964def348075c2d84bbdc3e6644fcf5a6236 100644 --- a/mongo/result.go +++ b/mongo/result.go @@ -33,7 +33,6 @@ import ( "gopkg.in/mgo.v2" "gopkg.in/mgo.v2/bson" "upper.io/db.v2" - "upper.io/db.v2/internal/logger" ) // result represents a query result. @@ -126,13 +125,15 @@ func (r *result) Select(fields ...interface{}) db.Result { // All dumps all results into a pointer to an slice of structs or maps. func (r *result) All(dst interface{}) (err error) { - if db.Debug { - var start, end int64 - start = time.Now().UnixNano() - defer func() { - end = time.Now().UnixNano() - logger.Log(r.debugQuery(fmt.Sprintf("find(%s)", mustJSON(r.queryChunks.Conditions))), nil, err, start, end) - }() + if db.Config.LoggingEnabled() { + defer func(start time.Time) { + db.Log(&db.QueryStatus{ + Query: fmt.Sprintf("find(%s)", mustJSON(r.queryChunks.Conditions)), + Err: err, + Start: start, + End: time.Now(), + }) + }(time.Now()) } err = r.setCursor() @@ -161,13 +162,15 @@ func (r *result) Group(fields ...interface{}) db.Result { // One fetches only one result from the resultset. func (r *result) One(dst interface{}) (err error) { - if db.Debug { - var start, end int64 - start = time.Now().UnixNano() - defer func() { - end = time.Now().UnixNano() - logger.Log(r.debugQuery(fmt.Sprintf("findOne(%s)", mustJSON(r.queryChunks.Conditions))), nil, err, start, end) - }() + if db.Config.LoggingEnabled() { + defer func(start time.Time) { + db.Log(&db.QueryStatus{ + Query: fmt.Sprintf("findOne(%s)", mustJSON(r.queryChunks.Conditions)), + Err: err, + Start: start, + End: time.Now(), + }) + }(time.Now()) } defer r.Close() @@ -193,13 +196,15 @@ func (r *result) Next(dst interface{}) bool { // Delete remove the matching items from the collection. func (r *result) Delete() (err error) { - if db.Debug { - var start, end int64 - start = time.Now().UnixNano() - defer func() { - end = time.Now().UnixNano() - logger.Log(r.debugQuery(fmt.Sprintf("remove(%s)", mustJSON(r.queryChunks.Conditions))), nil, err, start, end) - }() + if db.Config.LoggingEnabled() { + defer func(start time.Time) { + db.Log(&db.QueryStatus{ + Query: fmt.Sprintf("remove(%s)", mustJSON(r.queryChunks.Conditions)), + Err: err, + Start: start, + End: time.Now(), + }) + }(time.Now()) } _, err = r.c.collection.RemoveAll(r.queryChunks.Conditions) @@ -224,13 +229,15 @@ func (r *result) Close() error { func (r *result) Update(src interface{}) (err error) { updateSet := map[string]interface{}{"$set": src} - if db.Debug { - var start, end int64 - start = time.Now().UnixNano() - defer func() { - end = time.Now().UnixNano() - logger.Log(r.debugQuery(fmt.Sprintf("update(%s, %s)", mustJSON(r.queryChunks.Conditions), mustJSON(updateSet))), nil, err, start, end) - }() + if db.Config.LoggingEnabled() { + defer func(start time.Time) { + db.Log(&db.QueryStatus{ + Query: fmt.Sprintf("update(%s, %s)", mustJSON(r.queryChunks.Conditions), mustJSON(updateSet)), + Err: err, + Start: start, + End: time.Now(), + }) + }(time.Now()) } _, err = r.c.collection.UpdateAll(r.queryChunks.Conditions, updateSet) @@ -280,13 +287,15 @@ func (r *result) query() (*mgo.Query, error) { // Count counts matching elements. func (r *result) Count() (total uint64, err error) { - if db.Debug { - var start, end int64 - start = time.Now().UnixNano() - defer func() { - end = time.Now().UnixNano() - logger.Log(r.debugQuery(fmt.Sprintf("find(%s).count()", mustJSON(r.queryChunks.Conditions))), nil, err, start, end) - }() + if db.Config.LoggingEnabled() { + defer func(start time.Time) { + db.Log(&db.QueryStatus{ + Query: fmt.Sprintf("find(%s).count()", mustJSON(r.queryChunks.Conditions)), + Err: err, + Start: start, + End: time.Now(), + }) + }(time.Now()) } q := r.c.collection.Find(r.queryChunks.Conditions)