Squashed commit of the following:

commit c1bca95 Author: Kegsay <[email protected]> Date: Thu Apr 16 10:06:55 2020 +0100 Add SQL tracing via DENDRITE_TRACE_SQL (#968) * Add SQL tracing via DENDRITE_TRACE_SQL Add this to `internal/sqlutil` in preparation for #897 * Not entirely commit c2ea961 Author: Kegsay <[email protected]> Date: Wed Apr 15 17:48:40 2020 +0100 Add HTTP trace logging (#965) * Dump all requests/response server-side * Wrap in DENDRITE_TRACE * DENDRITE_TRACE_HTTP is better * Bugfix for response body and linting * False is true and true is false * Linting * How did this get missed * More linting
matrix-org · Apr 16, 2020 · 7615857 · 7615857
1 parent c98a72c
commit 7615857
Show file tree

Hide file tree

Showing 25 changed files with 259 additions and 23 deletions.
diff --git a/appservice/storage/postgres/storage.go b/appservice/storage/postgres/storage.go
@@ -21,6 +21,7 @@ import (
 
 	// Import postgres database driver
 	_ "github.com/lib/pq"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 	"github.com/matrix-org/gomatrixserverlib"
 )
 
@@ -35,7 +36,7 @@ type Database struct {
 func NewDatabase(dataSourceName string) (*Database, error) {
 	var result Database
 	var err error
-	if result.db, err = sql.Open("postgres", dataSourceName); err != nil {
+	if result.db, err = sqlutil.Open("postgres", dataSourceName); err != nil {
 		return nil, err
 	}
 	if err = result.prepare(); err != nil {

diff --git a/appservice/storage/sqlite3/storage.go b/appservice/storage/sqlite3/storage.go
@@ -21,6 +21,7 @@ import (
 
 	// Import SQLite database driver
 	"github.com/matrix-org/dendrite/common"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 	"github.com/matrix-org/gomatrixserverlib"
 	_ "github.com/mattn/go-sqlite3"
 )
@@ -36,7 +37,7 @@ type Database struct {
 func NewDatabase(dataSourceName string) (*Database, error) {
 	var result Database
 	var err error
-	if result.db, err = sql.Open(common.SQLiteDriverName(), dataSourceName); err != nil {
+	if result.db, err = sqlutil.Open(common.SQLiteDriverName(), dataSourceName); err != nil {
 		return nil, err
 	}
 	if err = result.prepare(); err != nil {

diff --git a/clientapi/auth/storage/accounts/postgres/storage.go b/clientapi/auth/storage/accounts/postgres/storage.go
@@ -22,6 +22,7 @@ import (
 
 	"github.com/matrix-org/dendrite/clientapi/auth/authtypes"
 	"github.com/matrix-org/dendrite/common"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 	"github.com/matrix-org/gomatrixserverlib"
 	"golang.org/x/crypto/bcrypt"
 
@@ -46,7 +47,7 @@ type Database struct {
 func NewDatabase(dataSourceName string, serverName gomatrixserverlib.ServerName) (*Database, error) {
 	var db *sql.DB
 	var err error
-	if db, err = sql.Open("postgres", dataSourceName); err != nil {
+	if db, err = sqlutil.Open("postgres", dataSourceName); err != nil {
 		return nil, err
 	}
 	partitions := common.PartitionOffsetStatements{}

diff --git a/clientapi/auth/storage/accounts/sqlite3/storage.go b/clientapi/auth/storage/accounts/sqlite3/storage.go
@@ -23,6 +23,7 @@ import (
 
 	"github.com/matrix-org/dendrite/clientapi/auth/authtypes"
 	"github.com/matrix-org/dendrite/common"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 	"github.com/matrix-org/gomatrixserverlib"
 	"golang.org/x/crypto/bcrypt"
 
@@ -49,7 +50,7 @@ type Database struct {
 func NewDatabase(dataSourceName string, serverName gomatrixserverlib.ServerName) (*Database, error) {
 	var db *sql.DB
 	var err error
-	if db, err = sql.Open(common.SQLiteDriverName(), dataSourceName); err != nil {
+	if db, err = sqlutil.Open(common.SQLiteDriverName(), dataSourceName); err != nil {
 		return nil, err
 	}
 	partitions := common.PartitionOffsetStatements{}

diff --git a/clientapi/auth/storage/devices/postgres/storage.go b/clientapi/auth/storage/devices/postgres/storage.go
@@ -22,6 +22,7 @@ import (
 
 	"github.com/matrix-org/dendrite/clientapi/auth/authtypes"
 	"github.com/matrix-org/dendrite/common"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 	"github.com/matrix-org/gomatrixserverlib"
 )
 
@@ -38,7 +39,7 @@ type Database struct {
 func NewDatabase(dataSourceName string, serverName gomatrixserverlib.ServerName) (*Database, error) {
 	var db *sql.DB
 	var err error
-	if db, err = sql.Open("postgres", dataSourceName); err != nil {
+	if db, err = sqlutil.Open("postgres", dataSourceName); err != nil {
 		return nil, err
 	}
 	d := devicesStatements{}

diff --git a/clientapi/auth/storage/devices/sqlite3/storage.go b/clientapi/auth/storage/devices/sqlite3/storage.go
@@ -22,6 +22,7 @@ import (
 
 	"github.com/matrix-org/dendrite/clientapi/auth/authtypes"
 	"github.com/matrix-org/dendrite/common"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 	"github.com/matrix-org/gomatrixserverlib"
 
 	_ "github.com/mattn/go-sqlite3"
@@ -40,7 +41,7 @@ type Database struct {
 func NewDatabase(dataSourceName string, serverName gomatrixserverlib.ServerName) (*Database, error) {
 	var db *sql.DB
 	var err error
-	if db, err = sql.Open(common.SQLiteDriverName(), dataSourceName); err != nil {
+	if db, err = sqlutil.Open(common.SQLiteDriverName(), dataSourceName); err != nil {
 		return nil, err
 	}
 	d := devicesStatements{}

diff --git a/common/basecomponent/base.go b/common/basecomponent/base.go
@@ -24,6 +24,7 @@ import (
 	"golang.org/x/crypto/ed25519"
 
 	"github.com/matrix-org/dendrite/common/keydb"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 	"github.com/matrix-org/gomatrixserverlib"
 	"github.com/matrix-org/naffka"
 
@@ -243,7 +244,7 @@ func setupNaffka(cfg *config.Dendrite) (sarama.Consumer, sarama.SyncProducer) {
 
 	uri, err := url.Parse(string(cfg.Database.Naffka))
 	if err != nil || uri.Scheme == "file" {
-		db, err = sql.Open(common.SQLiteDriverName(), string(cfg.Database.Naffka))
+		db, err = sqlutil.Open(common.SQLiteDriverName(), string(cfg.Database.Naffka))
 		if err != nil {
 			logrus.WithError(err).Panic("Failed to open naffka database")
 		}
@@ -253,7 +254,7 @@ func setupNaffka(cfg *config.Dendrite) (sarama.Consumer, sarama.SyncProducer) {
 			logrus.WithError(err).Panic("Failed to setup naffka database")
 		}
 	} else {
-		db, err = sql.Open("postgres", string(cfg.Database.Naffka))
+		db, err = sqlutil.Open("postgres", string(cfg.Database.Naffka))
 		if err != nil {
 			logrus.WithError(err).Panic("Failed to open naffka database")
 		}

diff --git a/common/httpapi.go b/common/httpapi.go
@@ -1,7 +1,12 @@
 package common
 
 import (
+	"io"
 	"net/http"
+	"net/http/httptest"
+	"net/http/httputil"
+	"os"
+	"strings"
 	"time"
 
 	"github.com/matrix-org/dendrite/clientapi/auth"
@@ -46,12 +51,60 @@ func MakeAuthAPI(
 // MakeExternalAPI turns a util.JSONRequestHandler function into an http.Handler.
 // This is used for APIs that are called from the internet.
 func MakeExternalAPI(metricsName string, f func(*http.Request) util.JSONResponse) http.Handler {
+	// TODO: We shouldn't be directly reading env vars here, inject it in instead.
+	// Refactor this when we split out config structs.
+	verbose := false
+	if os.Getenv("DENDRITE_TRACE_HTTP") == "1" {
+		verbose = true
+	}
 	h := util.MakeJSONAPI(util.NewJSONRequestHandler(f))
 	withSpan := func(w http.ResponseWriter, req *http.Request) {
+		nextWriter := w
+		if verbose {
+			logger := logrus.NewEntry(logrus.StandardLogger())
+			// Log outgoing response
+			rec := httptest.NewRecorder()
+			nextWriter = rec
+			defer func() {
+				resp := rec.Result()
+				dump, err := httputil.DumpResponse(resp, true)
+				if err != nil {
+					logger.Debugf("Failed to dump outgoing response: %s", err)
+				} else {
+					strSlice := strings.Split(string(dump), "\n")
+					for _, s := range strSlice {
+						logger.Debug(s)
+					}
+				}
+				// copy the response to the client
+				for hdr, vals := range resp.Header {
+					for _, val := range vals {
+						w.Header().Add(hdr, val)
+					}
+				}
+				w.WriteHeader(resp.StatusCode)
+				// discard errors as this is for debugging
+				_, _ = io.Copy(w, resp.Body)
+				_ = resp.Body.Close()
+			}()
+
+			// Log incoming request
+			dump, err := httputil.DumpRequest(req, true)
+			if err != nil {
+				logger.Debugf("Failed to dump incoming request: %s", err)
+			} else {
+				strSlice := strings.Split(string(dump), "\n")
+				for _, s := range strSlice {
+					logger.Debug(s)
+				}
+			}
+		}
+
 		span := opentracing.StartSpan(metricsName)
 		defer span.Finish()
 		req = req.WithContext(opentracing.ContextWithSpan(req.Context(), span))
-		h.ServeHTTP(w, req)
+		h.ServeHTTP(nextWriter, req)
+
 	}
 
 	return http.HandlerFunc(withSpan)

diff --git a/common/keydb/postgres/keydb.go b/common/keydb/postgres/keydb.go
@@ -17,11 +17,11 @@ package postgres
 
 import (
 	"context"
-	"database/sql"
 	"math"
 
 	"golang.org/x/crypto/ed25519"
 
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 	"github.com/matrix-org/gomatrixserverlib"
 )
 
@@ -41,7 +41,7 @@ func NewDatabase(
 	serverKey ed25519.PublicKey,
 	serverKeyID gomatrixserverlib.KeyID,
 ) (*Database, error) {
-	db, err := sql.Open("postgres", dataSourceName)
+	db, err := sqlutil.Open("postgres", dataSourceName)
 	if err != nil {
 		return nil, err
 	}

diff --git a/common/keydb/sqlite3/keydb.go b/common/keydb/sqlite3/keydb.go
@@ -17,12 +17,12 @@ package sqlite3
 
 import (
 	"context"
-	"database/sql"
 	"math"
 
 	"golang.org/x/crypto/ed25519"
 
 	"github.com/matrix-org/dendrite/common"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 	"github.com/matrix-org/gomatrixserverlib"
 
 	_ "github.com/mattn/go-sqlite3"
@@ -44,7 +44,7 @@ func NewDatabase(
 	serverKey ed25519.PublicKey,
 	serverKeyID gomatrixserverlib.KeyID,
 ) (*Database, error) {
-	db, err := sql.Open(common.SQLiteDriverName(), dataSourceName)
+	db, err := sqlutil.Open(common.SQLiteDriverName(), dataSourceName)
 	if err != nil {
 		return nil, err
 	}

diff --git a/federationsender/storage/postgres/storage.go b/federationsender/storage/postgres/storage.go
@@ -21,6 +21,7 @@ import (
 
 	"github.com/matrix-org/dendrite/common"
 	"github.com/matrix-org/dendrite/federationsender/types"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 )
 
 // Database stores information needed by the federation sender
@@ -35,7 +36,7 @@ type Database struct {
 func NewDatabase(dataSourceName string) (*Database, error) {
 	var result Database
 	var err error
-	if result.db, err = sql.Open("postgres", dataSourceName); err != nil {
+	if result.db, err = sqlutil.Open("postgres", dataSourceName); err != nil {
 		return nil, err
 	}
 	if err = result.prepare(); err != nil {

diff --git a/federationsender/storage/sqlite3/storage.go b/federationsender/storage/sqlite3/storage.go
@@ -23,6 +23,7 @@ import (
 
 	"github.com/matrix-org/dendrite/common"
 	"github.com/matrix-org/dendrite/federationsender/types"
+	"github.com/matrix-org/dendrite/internal/sqlutil"
 )
 
 // Database stores information needed by the federation sender
@@ -37,7 +38,7 @@ type Database struct {
 func NewDatabase(dataSourceName string) (*Database, error) {
 	var result Database
 	var err error
-	if result.db, err = sql.Open(common.SQLiteDriverName(), dataSourceName); err != nil {
+	if result.db, err = sqlutil.Open(common.SQLiteDriverName(), dataSourceName); err != nil {
 		return nil, err
 	}
 	if err = result.prepare(); err != nil {

diff --git a/go.mod b/go.mod
@@ -22,10 +22,12 @@ require (
 	github.com/matrix-org/util v0.0.0-20190711121626-527ce5ddefc7
 	github.com/mattn/go-sqlite3 v2.0.3+incompatible
 	github.com/nfnt/resize v0.0.0-20160724205520-891127d8d1b5
+	github.com/ngrok/sqlmw v0.0.0-20200129213757-d5c93a81bec6
 	github.com/opentracing/opentracing-go v1.1.0
 	github.com/pierrec/lz4 v2.5.0+incompatible // indirect
 	github.com/pkg/errors v0.9.1
 	github.com/prometheus/client_golang v1.4.1
+	github.com/prometheus/common v0.9.1
 	github.com/rcrowley/go-metrics v0.0.0-20200313005456-10cdbea86bc0 // indirect
 	github.com/sirupsen/logrus v1.4.2
 	github.com/tidwall/gjson v1.6.0 // indirect

diff --git a/go.sum b/go.sum
@@ -10,8 +10,10 @@ github.com/Shopify/toxiproxy v2.1.4+incompatible h1:TKdv8HiTLgE5wdJuEML90aBgNWso
 github.com/Shopify/toxiproxy v2.1.4+incompatible/go.mod h1:OXgGpZ6Cli1/URJOF1DMxUHB2q5Ap20/P/eIdh4G0pI=
 github.com/aead/siphash v1.0.1/go.mod h1:Nywa3cDsYNNK3gaciGTWPwHt0wlpNV15vwmswBAUSII=
 github.com/alecthomas/template v0.0.0-20160405071501-a0175ee3bccc/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc=
+github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751 h1:JYp7IbQjafoB+tBA3gMyHYHrpOtNuDiK/uB5uXxq5wM=
 github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc=
 github.com/alecthomas/units v0.0.0-20151022065526-2efee857e7cf/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0=
+github.com/alecthomas/units v0.0.0-20190717042225-c3de453c63f4 h1:Hs82Z41s6SdL1CELW+XaDYmOH4hkBN4/N9og/AsOv7E=
 github.com/alecthomas/units v0.0.0-20190717042225-c3de453c63f4/go.mod h1:ybxpYRFXyAe+OPACYpWeL0wqObRcbAqCMya13uyzqw0=
 github.com/armon/consul-api v0.0.0-20180202201655-eb2c6b5be1b6/go.mod h1:grANhF5doyWs3UAsr3K4I6qtAmlQcZDesFNEHPZAzj8=
 github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24TaqPxmxbtue+5NUziq4I4S80YR8gNf3Q=
@@ -452,6 +454,8 @@ github.com/nbio/st v0.0.0-20140626010706-e9e8d9816f32 h1:W6apQkHrMkS0Muv8G/TipAy
 github.com/nbio/st v0.0.0-20140626010706-e9e8d9816f32/go.mod h1:9wM+0iRr9ahx58uYLpLIr5fm8diHn0JbqRycJi6w0Ms=
 github.com/nfnt/resize v0.0.0-20160724205520-891127d8d1b5 h1:BvoENQQU+fZ9uukda/RzCAL/191HHwJA5b13R6diVlY=
 github.com/nfnt/resize v0.0.0-20160724205520-891127d8d1b5/go.mod h1:jpp1/29i3P1S/RLdc7JQKbRpFeM1dOBd8T9ki5s+AY8=
+github.com/ngrok/sqlmw v0.0.0-20200129213757-d5c93a81bec6 h1:evlcQnJY+v8XRRchV3hXzpHDl6GcEZeLXAhlH9Csdww=
+github.com/ngrok/sqlmw v0.0.0-20200129213757-d5c93a81bec6/go.mod h1:E26fwEtRNigBfFfHDWsklmo0T7Ixbg0XXgck+Hq4O9k=
 github.com/onsi/ginkgo v1.6.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/ginkgo v1.7.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/ginkgo v1.8.0 h1:VkHVNpR4iVnU8XQR6DBm8BqYjN7CRzw+xKUbVVbbW9w=
@@ -688,6 +692,7 @@ google.golang.org/grpc v1.19.0/go.mod h1:mqu4LbDTu4XGKhr4mRzUsmM4RtVoemTSY81AxZi
 google.golang.org/grpc v1.20.1/go.mod h1:10oTOabMzJvdu6/UiuZezV6QK5dSlG84ov/aaiqXj38=
 gopkg.in/Shopify/sarama.v1 v1.20.1 h1:Gi09A3fJXm0Jgt8kuKZ8YK+r60GfYn7MQuEmI3oq6hE=
 gopkg.in/Shopify/sarama.v1 v1.20.1/go.mod h1:AxnvoaevB2nBjNK17cG61A3LleFcWFwVBHBt+cot4Oc=
+gopkg.in/alecthomas/kingpin.v2 v2.2.6 h1:jMFz6MfLP0/4fUyZle81rXUoxOBFi19VUFKVDOQfozc=
 gopkg.in/alecthomas/kingpin.v2 v2.2.6/go.mod h1:FMv+mEhP44yOT+4EoQTLFTRgOQ1FBLkstjWtayDeSgw=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=