From b982aeb1028630d1df92e1a1b389dc76b6e0822f Mon Sep 17 00:00:00 2001 From: Jack Christensen Date: Thu, 5 Jun 2014 17:36:40 -0500 Subject: [PATCH] Improve logging some more --- conn.go | 92 ++++++++++++++++++++++++++++++++++++++++++--------------- 1 file changed, 69 insertions(+), 23 deletions(-) diff --git a/conn.go b/conn.go index 7e574750..51177555 100644 --- a/conn.go +++ b/conn.go @@ -338,14 +338,23 @@ func (c *Conn) selectFunc(sql string, onDataRow func(*DataRowReader) error, argu // sql can be either a prepared statement name or an SQL string. arguments will be // sanitized before being interpolated into sql strings. arguments should be referenced // positionally from the sql string as $1, $2, etc. -func (c *Conn) SelectRows(sql string, arguments ...interface{}) (rows []map[string]interface{}, err error) { - rows = make([]map[string]interface{}, 0, 8) +func (c *Conn) SelectRows(sql string, arguments ...interface{}) ([]map[string]interface{}, error) { + startTime := time.Now() + + rows := make([]map[string]interface{}, 0, 8) onDataRow := func(r *DataRowReader) error { rows = append(rows, c.rxDataRow(r)) return nil } - err = c.SelectFunc(sql, onDataRow, arguments...) - return + err := c.selectFunc(sql, onDataRow, arguments...) + if err != nil { + c.logger.Error("SelectRows", "sql", sql, "args", arguments, "error", err) + return nil, err + } + + endTime := time.Now() + c.logger.Info("SelectRows", "sql", sql, "args", arguments, "rowsFound", len(rows), "time", endTime.Sub(startTime)) + return rows, nil } // SelectRow executes sql and returns a map representing the found row. @@ -354,19 +363,31 @@ func (c *Conn) SelectRows(sql string, arguments ...interface{}) (rows []map[stri // positionally from the sql string as $1, $2, etc. // // Returns a NotSingleRowError if exactly one row is not found -func (c *Conn) SelectRow(sql string, arguments ...interface{}) (row map[string]interface{}, err error) { +func (c *Conn) SelectRow(sql string, arguments ...interface{}) (map[string]interface{}, error) { + startTime := time.Now() + var numRowsFound int64 + var row map[string]interface{} onDataRow := func(r *DataRowReader) error { numRowsFound++ row = c.rxDataRow(r) return nil } - err = c.SelectFunc(sql, onDataRow, arguments...) - if err == nil && numRowsFound != 1 { - err = NotSingleRowError{RowCount: numRowsFound} + err := c.selectFunc(sql, onDataRow, arguments...) + if err != nil { + c.logger.Error("SelectRow", "sql", sql, "args", arguments, "error", err) + return nil, err } - return + if numRowsFound != 1 { + err = NotSingleRowError{RowCount: numRowsFound} + row = nil + } + + endTime := time.Now() + c.logger.Info("SelectRow", "sql", sql, "args", arguments, "rowsFound", numRowsFound, "time", endTime.Sub(startTime)) + + return row, err } // SelectValue executes sql and returns a single value. sql can be either a prepared @@ -376,8 +397,11 @@ func (c *Conn) SelectRow(sql string, arguments ...interface{}) (row map[string]i // // Returns a UnexpectedColumnCountError if exactly one column is not found // Returns a NotSingleRowError if exactly one row is not found -func (c *Conn) SelectValue(sql string, arguments ...interface{}) (v interface{}, err error) { +func (c *Conn) SelectValue(sql string, arguments ...interface{}) (interface{}, error) { + startTime := time.Now() + var numRowsFound int64 + var v interface{} onDataRow := func(r *DataRowReader) error { if len(r.fields) != 1 { @@ -388,13 +412,20 @@ func (c *Conn) SelectValue(sql string, arguments ...interface{}) (v interface{}, v = r.ReadValue() return nil } - err = c.SelectFunc(sql, onDataRow, arguments...) - if err == nil { - if numRowsFound != 1 { - err = NotSingleRowError{RowCount: numRowsFound} - } + err := c.selectFunc(sql, onDataRow, arguments...) + if err != nil { + c.logger.Error("SelectValue", "sql", sql, "args", arguments, "error", err) + return nil, err } - return + if numRowsFound != 1 { + err = NotSingleRowError{RowCount: numRowsFound} + v = nil + } + + endTime := time.Now() + c.logger.Info("SelectValue", "sql", sql, "args", arguments, "rowsFound", numRowsFound, "time", endTime.Sub(startTime)) + + return v, err } // SelectValueTo executes sql that returns a single value and writes that value to w. @@ -408,14 +439,20 @@ func (c *Conn) SelectValue(sql string, arguments ...interface{}) (v interface{}, // Returns a UnexpectedColumnCountError if exactly one column is not found // Returns a NotSingleRowError if exactly one row is not found func (c *Conn) SelectValueTo(w io.Writer, sql string, arguments ...interface{}) (err error) { + startTime := time.Now() + defer func() { - if err != nil { + if err == nil { + endTime := time.Now() + c.logger.Info("SelectValueTo", "sql", sql, "args", arguments, "time", endTime.Sub(startTime)) + } else { c.logger.Error(fmt.Sprintf("SelectValueTo `%s` with %v failed: %v", sql, arguments, err)) } }() - if err = c.sendQuery(sql, arguments...); err != nil { - return + err = c.sendQuery(sql, arguments...) + if err != nil { + return err } var numRowsFound int64 @@ -506,8 +543,10 @@ func (c *Conn) rxDataRowValueTo(w io.Writer, bodySize int32) (err error) { // the sql string as $1, $2, etc. // // Returns a UnexpectedColumnCountError if exactly one column is not found -func (c *Conn) SelectValues(sql string, arguments ...interface{}) (values []interface{}, err error) { - values = make([]interface{}, 0, 8) +func (c *Conn) SelectValues(sql string, arguments ...interface{}) ([]interface{}, error) { + startTime := time.Now() + + values := make([]interface{}, 0, 8) onDataRow := func(r *DataRowReader) error { if len(r.fields) != 1 { return UnexpectedColumnCountError{ExpectedCount: 1, ActualCount: int16(len(r.fields))} @@ -516,8 +555,15 @@ func (c *Conn) SelectValues(sql string, arguments ...interface{}) (values []inte values = append(values, r.ReadValue()) return nil } - err = c.SelectFunc(sql, onDataRow, arguments...) - return + err := c.selectFunc(sql, onDataRow, arguments...) + if err != nil { + c.logger.Error("SelectValues", "sql", sql, "args", arguments, "error", err) + return nil, err + } + + endTime := time.Now() + c.logger.Info("SelectValues", "sql", sql, "args", arguments, "valuesFound", len(values), "time", endTime.Sub(startTime)) + return values, nil } // Prepare creates a prepared statement with name and sql. sql can contain placeholders