diff --git a/go/mysql/server.go b/go/mysql/server.go index 204d23b8685..153697b9ac3 100644 --- a/go/mysql/server.go +++ b/go/mysql/server.go @@ -19,6 +19,7 @@ package mysql import ( "context" "crypto/tls" + "fmt" "io" "net" "strings" @@ -316,6 +317,11 @@ func (l *Listener) handle(conn net.Conn, connectionID uint32, acceptTime time.Ti c := newServerConn(conn, l) c.ConnectionID = connectionID + t := time.Now() + defer func() { + fmt.Printf("CLOSE CONNECTION %d [%v] \n", connectionID, time.Since(t)) + }() + // Catch panics, and close the connection in any case. defer func() { if x := recover(); x != nil { @@ -466,9 +472,11 @@ func (l *Listener) handle(conn net.Conn, connectionID uint32, acceptTime time.Ti // Set initial db name. if c.schemaName != "" { + fmt.Printf("handshake use %s\n", c.schemaName) err = l.handler.ComQuery(c, "use "+sqlescape.EscapeID(c.schemaName), func(result *sqltypes.Result) error { return nil }) + fmt.Printf("handshake use %s %v [%s]\n", c.schemaName, err, time.Now().Sub(t)) if err != nil { c.writeErrorPacketFromError(err) return @@ -491,6 +499,8 @@ func (l *Listener) handle(conn net.Conn, connectionID uint32, acceptTime time.Ti log.Warningf("Slow connection from %s: %v", c, connectTime) } + fmt.Printf("Connection %d connectTime %s\n", connectionID, connectTime) + // Tell our handler that we're finished handshake and are ready to // process commands. l.handler.ConnectionReady(c) diff --git a/go/vt/vtgateproxy/mysql_server.go b/go/vt/vtgateproxy/mysql_server.go index 27ad82d187b..b4154a77bec 100644 --- a/go/vt/vtgateproxy/mysql_server.go +++ b/go/vt/vtgateproxy/mysql_server.go @@ -179,6 +179,15 @@ func (ph *proxyHandler) ComQuery(c *mysql.Conn, query string, callback func(*sql defer cancel() } + t := time.Now() + defer func() { + logSql := query + if len(logSql) > 40 { + logSql = logSql[:40] + } + fmt.Printf("ComQuery conn %d %s [%s]\n", c.ConnectionID, logSql, time.Since(t)) + }() + span, ctx, err := startSpan(ctx, query, "proxyHandler.ComQuery") if err != nil { return vterrors.Wrap(err, "failed to extract span") diff --git a/go/vt/vtgateproxy/vtgateproxy.go b/go/vt/vtgateproxy/vtgateproxy.go index 0b9e44b8dc4..d241e33f604 100644 --- a/go/vt/vtgateproxy/vtgateproxy.go +++ b/go/vt/vtgateproxy/vtgateproxy.go @@ -118,11 +118,15 @@ func (proxy *VTGateProxy) Prepare(ctx context.Context, session *vtgateconn.VTGat } func (proxy *VTGateProxy) Execute(ctx context.Context, session *vtgateconn.VTGateSession, sql string, bindVariables map[string]*querypb.BindVariable) (qr *sqltypes.Result, err error) { - if proxy.conn == nil { - return nil, vterrors.Errorf(vtrpcpb.Code_UNAVAILABLE, "not connnected") + t := time.Now() + qr, err = session.Execute(ctx, sql, bindVariables) + logSql := sql + if len(logSql) > 40 { + logSql = logSql[:40] } + fmt.Printf("Execute %s [%s]\n", logSql, time.Since(t)) + return qr, err - return session.Execute(ctx, sql, bindVariables) } func (proxy *VTGateProxy) StreamExecute(ctx context.Context, session *vtgateconn.VTGateSession, sql string, bindVariables map[string]*querypb.BindVariable, callback func(*sqltypes.Result) error) error {