diff options
| -rw-r--r-- | _example/trace/main.go | 264 | ||||
| -rw-r--r-- | sqlite3.go | 52 | ||||
| -rw-r--r-- | tracecallback.go | 234 |
3 files changed, 550 insertions, 0 deletions
diff --git a/_example/trace/main.go b/_example/trace/main.go new file mode 100644 index 0000000..6a2953f --- /dev/null +++ b/_example/trace/main.go @@ -0,0 +1,264 @@ +package main + +import ( + "database/sql" + "fmt" + "log" + "os" + + sqlite3 "github.com/gimpldo/go-sqlite3" +) + +func traceCallback(info sqlite3.TraceInfo) int { + // Not very readable but may be useful; uncomment next line in case of doubt: + //fmt.Printf("Trace: %#v\n", info) + + var dbErrText string + if info.DBError.Code != 0 || info.DBError.ExtendedCode != 0 { + dbErrText = fmt.Sprintf("; DB error: %#v", info.DBError) + } else { + dbErrText = "." + } + + // Show the Statement-or-Trigger text in curly braces ('{', '}') + // since from the *paired* ASCII characters they are + // the least used in SQL syntax, therefore better visual delimiters. + // Maybe show 'ExpandedSQL' the same way as 'StmtOrTrigger'. + // + // A known use of curly braces (outside strings) is + // for ODBC escape sequences. Not likely to appear here. + // + // Template languages, etc. don't matter, we should see their *result* + // at *this* level. + // Strange curly braces in SQL code that reached the database driver + // suggest that there is a bug in the application. + // The braces are likely to be either template syntax or + // a programming language's string interpolation syntax. + + var expandedText string + if info.ExpandedSQL != "" { + if info.ExpandedSQL == info.StmtOrTrigger { + expandedText = " = exp" + } else { + expandedText = fmt.Sprintf(" expanded {%q}", info.ExpandedSQL) + } + } else { + expandedText = "" + } + + // SQLite docs as of September 6, 2016: Tracing and Profiling Functions + // https://www.sqlite.org/c3ref/profile.html + // + // The profile callback time is in units of nanoseconds, however + // the current implementation is only capable of millisecond resolution + // so the six least significant digits in the time are meaningless. + // Future versions of SQLite might provide greater resolution on the profiler callback. + + var runTimeText string + if info.RunTimeNanosec == 0 { + if info.EventCode == sqlite3.TraceProfile { + //runTimeText = "; no time" // seems confusing + runTimeText = "; time 0" // no measurement unit + } else { + //runTimeText = "; no time" // seems useless and confusing + } + } else { + const nanosPerMillisec = 1000000 + if info.RunTimeNanosec%nanosPerMillisec == 0 { + runTimeText = fmt.Sprintf("; time %d ms", info.RunTimeNanosec/nanosPerMillisec) + } else { + // unexpected: better than millisecond resolution + runTimeText = fmt.Sprintf("; time %d ns!!!", info.RunTimeNanosec) + } + } + + var modeText string + if info.AutoCommit { + modeText = "-AC-" + } else { + modeText = "+Tx+" + } + + fmt.Printf("Trace: ev %d %s conn 0x%x, stmt 0x%x {%q}%s%s%s\n", + info.EventCode, modeText, info.ConnHandle, info.StmtHandle, + info.StmtOrTrigger, expandedText, + runTimeText, + dbErrText) + return 0 +} + +func main() { + eventMask := sqlite3.TraceStmt | sqlite3.TraceProfile | sqlite3.TraceRow | sqlite3.TraceClose + + sql.Register("sqlite3_tracing", + &sqlite3.SQLiteDriver{ + ConnectHook: func(conn *sqlite3.SQLiteConn) error { + err := conn.SetTrace(&sqlite3.TraceConfig{ + Callback: traceCallback, + EventMask: uint(eventMask), + WantExpandedSQL: true, + }) + return err + }, + }) + + os.Exit(dbMain()) +} + +// Harder to do DB work in main(). +// It's better with a separate function because +// 'defer' and 'os.Exit' don't go well together. +// +// DO NOT use 'log.Fatal...' below: remember that it's equivalent to +// Print() followed by a call to os.Exit(1) --- and +// we want to avoid Exit() so 'defer' can do cleanup. +// Use 'log.Panic...' instead. + +func dbMain() int { + db, err := sql.Open("sqlite3_tracing", ":memory:") + if err != nil { + fmt.Printf("Failed to open database: %#+v\n", err) + return 1 + } + defer db.Close() + + err = db.Ping() + if err != nil { + log.Panic(err) + } + + dbSetup(db) + + dbDoInsert(db) + dbDoInsertPrepared(db) + dbDoSelect(db) + dbDoSelectPrepared(db) + + return 0 +} + +// 'DDL' stands for "Data Definition Language": + +// Note: "INTEGER PRIMARY KEY NOT NULL AUTOINCREMENT" causes the error +// 'near "AUTOINCREMENT": syntax error'; without "NOT NULL" it works. +const tableDDL = `CREATE TABLE t1 ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + note VARCHAR NOT NULL +)` + +// 'DML' stands for "Data Manipulation Language": + +const insertDML = "INSERT INTO t1 (note) VALUES (?)" +const selectDML = "SELECT id, note FROM t1 WHERE note LIKE ?" + +const textPrefix = "bla-1234567890-" +const noteTextPattern = "%Prep%" + +const nGenRows = 4 // Number of Rows to Generate (for *each* approach tested) + +func dbSetup(db *sql.DB) { + var err error + + _, err = db.Exec("DROP TABLE IF EXISTS t1") + if err != nil { + log.Panic(err) + } + _, err = db.Exec(tableDDL) + if err != nil { + log.Panic(err) + } +} + +func dbDoInsert(db *sql.DB) { + const Descr = "DB-Exec" + for i := 0; i < nGenRows; i++ { + result, err := db.Exec(insertDML, textPrefix+Descr) + if err != nil { + log.Panic(err) + } + + resultDoCheck(result, Descr, i) + } +} + +func dbDoInsertPrepared(db *sql.DB) { + const Descr = "DB-Prepare" + + stmt, err := db.Prepare(insertDML) + if err != nil { + log.Panic(err) + } + defer stmt.Close() + + for i := 0; i < nGenRows; i++ { + result, err := stmt.Exec(textPrefix + Descr) + if err != nil { + log.Panic(err) + } + + resultDoCheck(result, Descr, i) + } +} + +func resultDoCheck(result sql.Result, callerDescr string, callIndex int) { + lastID, err := result.LastInsertId() + if err != nil { + log.Panic(err) + } + nAffected, err := result.RowsAffected() + if err != nil { + log.Panic(err) + } + + log.Printf("Exec result for %s (%d): ID = %d, affected = %d\n", callerDescr, callIndex, lastID, nAffected) +} + +func dbDoSelect(db *sql.DB) { + const Descr = "DB-Query" + + rows, err := db.Query(selectDML, noteTextPattern) + if err != nil { + log.Panic(err) + } + defer rows.Close() + + rowsDoFetch(rows, Descr) +} + +func dbDoSelectPrepared(db *sql.DB) { + const Descr = "DB-Prepare" + + stmt, err := db.Prepare(selectDML) + if err != nil { + log.Panic(err) + } + defer stmt.Close() + + rows, err := stmt.Query(noteTextPattern) + if err != nil { + log.Panic(err) + } + defer rows.Close() + + rowsDoFetch(rows, Descr) +} + +func rowsDoFetch(rows *sql.Rows, callerDescr string) { + var nRows int + var id int64 + var note string + + for rows.Next() { + err := rows.Scan(&id, ¬e) + if err != nil { + log.Panic(err) + } + log.Printf("Row for %s (%d): id=%d, note=%q\n", + callerDescr, nRows, id, note) + nRows++ + } + if err := rows.Err(); err != nil { + log.Panic(err) + } + log.Printf("Total %d rows for %s.\n", nRows, callerDescr) +} @@ -9,6 +9,7 @@ package sqlite3 #cgo CFLAGS: -std=gnu99 #cgo CFLAGS: -DSQLITE_ENABLE_RTREE -DSQLITE_THREADSAFE #cgo CFLAGS: -DSQLITE_ENABLE_FTS3 -DSQLITE_ENABLE_FTS3_PARENTHESIS -DSQLITE_ENABLE_FTS4_UNICODE61 +#cgo CFLAGS: -DSQLITE_TRACE_SIZE_LIMIT=15 #ifndef USE_LIBSQLITE3 #include <sqlite3-binding.h> #else @@ -99,6 +100,8 @@ int _sqlite3_create_function( void callbackTrampoline(sqlite3_context*, int, sqlite3_value**); void stepTrampoline(sqlite3_context*, int, sqlite3_value**); void doneTrampoline(sqlite3_context*); + +void traceCallbackTrampoline(unsigned traceEventCode, void *ctx, void *p, void *x); */ import "C" import ( @@ -513,6 +516,55 @@ func (c *SQLiteConn) RegisterAggregator(name string, impl interface{}, pure bool return nil } +// SetTrace installs or removes the trace callback for the given database connection. +// It's not named 'RegisterTrace' because only one callback can be kept and called. +// Calling SetTrace a second time on same database connection +// overrides (cancels) any prior callback and all its settings: +// event mask, etc. +func (c *SQLiteConn) SetTrace(requested *TraceConfig) error { + connHandle := uintptr(unsafe.Pointer(c.db)) + + _, _ = popTraceMapping(connHandle) + + if requested == nil { + // The traceMap entry was deleted already by popTraceMapping(): + // can disable all events now, no need to watch for TraceClose. + err := c.setSQLiteTrace(0) + return err + } + + reqCopy := *requested + + // Disable potentially expensive operations + // if their result will not be used. We are doing this + // just in case the caller provided nonsensical input. + if reqCopy.EventMask&TraceStmt == 0 { + reqCopy.WantExpandedSQL = false + } + + addTraceMapping(connHandle, reqCopy) + + // The callback trampoline function does cleanup on Close event, + // regardless of the presence or absence of the user callback. + // Therefore it needs the Close event to be selected: + actualEventMask := reqCopy.EventMask | TraceClose + err := c.setSQLiteTrace(actualEventMask) + return err +} + +func (c *SQLiteConn) setSQLiteTrace(sqliteEventMask uint) error { + rv := C.sqlite3_trace_v2(c.db, + C.uint(sqliteEventMask), + (*[0]byte)(unsafe.Pointer(C.traceCallbackTrampoline)), + unsafe.Pointer(c.db)) // Fourth arg is same as first: we are + // passing the database connection handle as callback context. + + if rv != C.SQLITE_OK { + return c.lastError() + } + return nil +} + // AutoCommit return which currently auto commit or not. func (c *SQLiteConn) AutoCommit() bool { return int(C.sqlite3_get_autocommit(c.db)) != 0 diff --git a/tracecallback.go b/tracecallback.go new file mode 100644 index 0000000..6291fe2 --- /dev/null +++ b/tracecallback.go @@ -0,0 +1,234 @@ +// Copyright (C) 2016 Yasuhiro Matsumoto <mattn.jp@gmail.com>. +// TODO: add "Gimpl do foo" team? +// +// Use of this source code is governed by an MIT-style +// license that can be found in the LICENSE file. + +package sqlite3 + +/* +#ifndef USE_LIBSQLITE3 +#include <sqlite3-binding.h> +#else +#include <sqlite3.h> +#endif +#include <stdlib.h> +*/ +import "C" + +import ( + "fmt" + "strings" + "sync" + "unsafe" +) + +// Trace... constants identify the possible events causing callback invocation. +// Values are same as the corresponding SQLite Trace Event Codes. +const ( + TraceStmt = C.SQLITE_TRACE_STMT + TraceProfile = C.SQLITE_TRACE_PROFILE + TraceRow = C.SQLITE_TRACE_ROW + TraceClose = C.SQLITE_TRACE_CLOSE +) + +type TraceInfo struct { + // Pack together the shorter fields, to keep the struct smaller. + // On a 64-bit machine there would be padding + // between EventCode and ConnHandle; having AutoCommit here is "free": + EventCode uint32 + AutoCommit bool + ConnHandle uintptr + + // Usually filled, unless EventCode = TraceClose = SQLITE_TRACE_CLOSE: + // identifier for a prepared statement: + StmtHandle uintptr + + // Two strings filled when EventCode = TraceStmt = SQLITE_TRACE_STMT: + // (1) either the unexpanded SQL text of the prepared statement, or + // an SQL comment that indicates the invocation of a trigger; + // (2) expanded SQL, if requested and if (1) is not an SQL comment. + StmtOrTrigger string + ExpandedSQL string // only if requested (TraceConfig.WantExpandedSQL = true) + + // filled when EventCode = TraceProfile = SQLITE_TRACE_PROFILE: + // estimated number of nanoseconds that the prepared statement took to run: + RunTimeNanosec int64 + + DBError Error +} + +// TraceUserCallback gives the signature for a trace function +// provided by the user (Go application programmer). +// SQLite 3.14 documentation (as of September 2, 2016) +// for SQL Trace Hook = sqlite3_trace_v2(): +// The integer return value from the callback is currently ignored, +// though this may change in future releases. Callback implementations +// should return zero to ensure future compatibility. +type TraceUserCallback func(TraceInfo) int + +type TraceConfig struct { + Callback TraceUserCallback + EventMask uint + WantExpandedSQL bool +} + +func fillDBError(dbErr *Error, db *C.sqlite3) { + // See SQLiteConn.lastError(), in file 'sqlite3.go' at the time of writing (Sept 5, 2016) + dbErr.Code = ErrNo(C.sqlite3_errcode(db)) + dbErr.ExtendedCode = ErrNoExtended(C.sqlite3_extended_errcode(db)) + dbErr.err = C.GoString(C.sqlite3_errmsg(db)) +} + +func fillExpandedSQL(info *TraceInfo, db *C.sqlite3, pStmt unsafe.Pointer) { + if pStmt == nil { + panic("No SQLite statement pointer in P arg of trace_v2 callback") + } + + expSQLiteCStr := C.sqlite3_expanded_sql(pStmt) + if expSQLiteCStr == nil { + fillDBError(&info.DBError, db) + return + } + info.ExpandedSQL = C.GoString(expSQLiteCStr) +} + +//export traceCallbackTrampoline +func traceCallbackTrampoline( + traceEventCode uint, + // Parameter named 'C' in SQLite docs = Context given at registration: + ctx unsafe.Pointer, + // Parameter named 'P' in SQLite docs (Primary event data?): + p unsafe.Pointer, + // Parameter named 'X' in SQLite docs (eXtra event data?): + xValue unsafe.Pointer) int { + + if ctx == nil { + panic(fmt.Sprintf("No context (ev 0x%x)", traceEventCode)) + } + + contextDB := (*C.sqlite3)(ctx) + connHandle := uintptr(ctx) + + var traceConf TraceConfig + var found bool + if traceEventCode == TraceClose { + // clean up traceMap: 'pop' means get and delete + traceConf, found = popTraceMapping(connHandle) + } else { + traceConf, found = lookupTraceMapping(connHandle) + } + + if !found { + panic(fmt.Sprintf("Mapping not found for handle 0x%x (ev 0x%x)", + connHandle, traceEventCode)) + } + + var info TraceInfo + + info.EventCode = uint32(traceEventCode) + info.AutoCommit = (int(C.sqlite3_get_autocommit(contextDB)) != 0) + info.ConnHandle = connHandle + + switch traceEventCode { + case TraceStmt: + info.StmtHandle = uintptr(p) + + var xStr string + if xValue != nil { + xStr = C.GoString((*C.char)(xValue)) + } + info.StmtOrTrigger = xStr + if !strings.HasPrefix(xStr, "--") { + // Not SQL comment, therefore the current event + // is not related to a trigger. + // The user might want to receive the expanded SQL; + // let's check: + if traceConf.WantExpandedSQL { + fillExpandedSQL(&info, contextDB, p) + } + } + + case TraceProfile: + info.StmtHandle = uintptr(p) + + if xValue == nil { + panic("NULL pointer in X arg of trace_v2 callback for SQLITE_TRACE_PROFILE event") + } + + info.RunTimeNanosec = *(*int64)(xValue) + + // sample the error //TODO: is it safe? is it useful? + fillDBError(&info.DBError, contextDB) + + case TraceRow: + info.StmtHandle = uintptr(p) + + case TraceClose: + handle := uintptr(p) + if handle != info.ConnHandle { + panic(fmt.Sprintf("Different conn handle 0x%x (expected 0x%x) in SQLITE_TRACE_CLOSE event.", + handle, info.ConnHandle)) + } + + default: + // Pass unsupported events to the user callback (if configured); + // let the user callback decide whether to panic or ignore them. + } + + // Do not execute user callback when the event was not requested by user! + // Remember that the Close event is always selected when + // registering this callback trampoline with SQLite --- for cleanup. + // In the future there may be more events forced to "selected" in SQLite + // for the driver's needs. + if traceConf.EventMask&traceEventCode == 0 { + return 0 + } + + r := 0 + if traceConf.Callback != nil { + r = traceConf.Callback(info) + } + return r +} + +type traceMapEntry struct { + config TraceConfig +} + +var traceMapLock sync.Mutex +var traceMap = make(map[uintptr]traceMapEntry) + +func addTraceMapping(connHandle uintptr, traceConf TraceConfig) { + traceMapLock.Lock() + defer traceMapLock.Unlock() + + oldEntryCopy, found := traceMap[connHandle] + if found { + panic(fmt.Sprintf("Adding trace config %v: handle 0x%x already registered (%v).", + traceConf, connHandle, oldEntryCopy.config)) + } + traceMap[connHandle] = traceMapEntry{config: traceConf} + fmt.Printf("Added trace config %v: handle 0x%x.\n", traceConf, connHandle) +} + +func lookupTraceMapping(connHandle uintptr) (TraceConfig, bool) { + traceMapLock.Lock() + defer traceMapLock.Unlock() + + entryCopy, found := traceMap[connHandle] + return entryCopy.config, found +} + +// 'pop' = get and delete from map before returning the value to the caller +func popTraceMapping(connHandle uintptr) (TraceConfig, bool) { + traceMapLock.Lock() + defer traceMapLock.Unlock() + + entryCopy, found := traceMap[connHandle] + if found { + delete(traceMap, connHandle) + fmt.Printf("Pop handle 0x%x: deleted trace config %v.\n", connHandle, entryCopy.config) + } + return entryCopy.config, found +} |