diff --git a/build.sh b/build.sh index 34e4b115..734ec728 100755 --- a/build.sh +++ b/build.sh @@ -8,6 +8,6 @@ export BUILD=`git rev-parse --short HEAD || ""` export FLAGS="-X github.com/matrix-org/dendrite/internal.branch=$BRANCH -X github.com/matrix-org/dendrite/internal.build=$BUILD" -go install -trimpath -ldflags "$FLAGS" -v $PWD/`dirname $0`/cmd/... +go install --tags "sqlite_trace" -trimpath -ldflags "$FLAGS" -v $PWD/`dirname $0`/cmd/... -GOOS=js GOARCH=wasm go build -trimpath -ldflags "$FLAGS" -o main.wasm ./cmd/dendritejs +#GOOS=js GOARCH=wasm go build -trimpath -ldflags "$FLAGS" -o main.wasm ./cmd/dendritejs diff --git a/internal/sqlutil/trace_driver.go b/internal/sqlutil/trace_driver.go index f123b1e4..5828e452 100644 --- a/internal/sqlutil/trace_driver.go +++ b/internal/sqlutil/trace_driver.go @@ -18,9 +18,12 @@ package sqlutil import ( "database/sql" + "fmt" + + log "github.com/sirupsen/logrus" "github.com/lib/pq" - sqlite "github.com/mattn/go-sqlite3" + sqlite3 "github.com/mattn/go-sqlite3" "github.com/ngrok/sqlmw" ) @@ -30,6 +33,99 @@ func registerDrivers() { } // install the wrapped drivers sql.Register("postgres-trace", sqlmw.Driver(&pq.Driver{}, new(traceInterceptor))) - sql.Register("sqlite3-trace", sqlmw.Driver(&sqlite.SQLiteDriver{}, new(traceInterceptor))) + + //sql.Register("sqlite3-trace", sqlmw.Driver(&sqlite.SQLiteDriver{}, new(traceInterceptor))) + + eventMask := sqlite3.TraceStmt | sqlite3.TraceProfile | sqlite3.TraceRow | sqlite3.TraceClose + + sql.Register("sqlite3-trace", + &sqlite3.SQLiteDriver{ + ConnectHook: func(conn *sqlite3.SQLiteConn) error { + err := conn.SetTrace(&sqlite3.TraceConfig{ + Callback: traceCallback, + EventMask: eventMask, + WantExpandedSQL: true, + }) + return err + }, + }) } + +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+" + } + + log.Infof("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 +} \ No newline at end of file