execute batch wiring and example.

go/vt/logutil/console_logger.go

@@ -6,9 +6,7 @@ import (
 	log "github.com/golang/glog"
 )
 
-// ConsoleLogger is a Logger that uses glog directly to log.
-// We can't specify the depth of the stack trace,
-// So we just find it and add it to the message.
+// ConsoleLogger is a Logger that uses glog directly to log, at the right level.
 type ConsoleLogger struct{}
 
 // NewConsoleLogger returns a simple ConsoleLogger
@@ -18,26 +16,17 @@ func NewConsoleLogger() ConsoleLogger {
 
 // Infof is part of the Logger interface
 func (cl ConsoleLogger) Infof(format string, v ...interface{}) {
-	file, line := fileAndLine(3)
-	vals := []interface{}{file, line}
-	vals = append(vals, v...)
-	log.Infof("%v:%v] "+format, vals...)
+	log.InfoDepth(2, fmt.Sprintf(format, v...))
 }
 
 // Warningf is part of the Logger interface
 func (cl ConsoleLogger) Warningf(format string, v ...interface{}) {
-	file, line := fileAndLine(3)
-	vals := []interface{}{file, line}
-	vals = append(vals, v...)
-	log.Warningf("%v:%v] "+format, vals...)
+	log.WarningDepth(2, fmt.Sprintf(format, v...))
 }
 
 // Errorf is part of the Logger interface
 func (cl ConsoleLogger) Errorf(format string, v ...interface{}) {
-	file, line := fileAndLine(3)
-	vals := []interface{}{file, line}
-	vals = append(vals, v...)
-	log.Errorf("%v:%v] "+format, vals...)
+	log.ErrorDepth(2, fmt.Sprintf(format, v...))
 }
 
 // Printf is part of the Logger interface

go/vt/logutil/throttled.go

@@ -1,6 +1,7 @@
 package logutil
 
 import (
+	"fmt"
 	"sync"
 	"time"
 
@@ -29,12 +30,12 @@ func NewThrottledLogger(name string, maxInterval time.Duration) *ThrottledLogger
 	}
 }
 
-type logFunc func(string, ...interface{})
+type logFunc func(int, ...interface{})
 
 var (
-	infof    = log.Infof
-	warningf = log.Warningf
-	errorf   = log.Errorf
+	infoDepth    = log.InfoDepth
+	warningDepth = log.WarningDepth
+	errorDepth   = log.ErrorDepth
 )
 
 func (tl *ThrottledLogger) log(logF logFunc, format string, v ...interface{}) {
@@ -45,7 +46,7 @@ func (tl *ThrottledLogger) log(logF logFunc, format string, v ...interface{}) {
 	logWaitTime := tl.maxInterval - (now.Sub(tl.lastlogTime))
 	if logWaitTime < 0 {
 		tl.lastlogTime = now
-		logF(tl.name+":"+format, v...)
+		logF(2, fmt.Sprintf(tl.name+":"+format, v...))
 		return
 	}
 	// If this is the first message to be skipped, start a goroutine
@@ -55,7 +56,9 @@ func (tl *ThrottledLogger) log(logF logFunc, format string, v ...interface{}) {
 			time.Sleep(d)
 			tl.mu.Lock()
 			defer tl.mu.Unlock()
-			logF("%v: skipped %v log messages", tl.name, tl.skippedCount)
+			// Because of the go func(), we lose the stack trace,
+			// so we just use the current line for this.
+			logF(0, fmt.Sprintf("%v: skipped %v log messages", tl.name, tl.skippedCount))
 			tl.skippedCount = 0
 		}(logWaitTime)
 	}
@@ -64,15 +67,15 @@ func (tl *ThrottledLogger) log(logF logFunc, format string, v ...interface{}) {
 
 // Infof logs an info if not throttled.
 func (tl *ThrottledLogger) Infof(format string, v ...interface{}) {
-	tl.log(infof, format, v...)
+	tl.log(infoDepth, format, v...)
 }
 
 // Warningf logs a warning if not throttled.
 func (tl *ThrottledLogger) Warningf(format string, v ...interface{}) {
-	tl.log(warningf, format, v...)
+	tl.log(warningDepth, format, v...)
 }
 
 // Errorf logs an error if not throttled.
 func (tl *ThrottledLogger) Errorf(format string, v ...interface{}) {
-	tl.log(errorf, format, v...)
+	tl.log(errorDepth, format, v...)
 }

go/vt/logutil/throttled_test.go

@@ -9,8 +9,8 @@ import (
 func TestThrottledLogger(t *testing.T) {
 	// Install a fake log func for testing.
 	log := make(chan string)
-	infof = func(format string, args ...interface{}) {
-		log <- fmt.Sprintf(format, args...)
+	infoDepth = func(depth int, args ...interface{}) {
+		log <- fmt.Sprint(args...)
 	}
 	interval := 100 * time.Millisecond
 	tl := NewThrottledLogger("name", interval)

go/vt/tabletserver/query_executor.go

@@ -252,7 +252,7 @@ func (qre *QueryExecutor) fetchMulti(pkRows [][]sqltypes.Value, limit int64) (re
 	qre.logStats.CacheAbsent = absent
 	qre.logStats.CacheMisses = misses
 
-	qre.logStats.QuerySources |= QUERY_SOURCE_ROWCACHE
+	qre.logStats.QuerySources |= QuerySourceRowcache
 
 	tableInfo.hits.Add(hits)
 	tableInfo.absent.Add(absent)
@@ -538,7 +538,7 @@ func (qre *QueryExecutor) qFetch(logStats *SQLQueryStats, parsedQuery *sqlparser
 			q.Result, q.Err = qre.execSQLNoPanic(conn, sql, false)
 		}
 	} else {
-		logStats.QuerySources |= QUERY_SOURCE_CONSOLIDATOR
+		logStats.QuerySources |= QuerySourceConsolidator
 		startTime := time.Now()
 		q.Wait()
 		waitStats.Record("Consolidations", startTime)

go/vt/tabletserver/query_executor_test.go

@@ -6,7 +6,6 @@ package tabletserver
 
 import (
 	"fmt"
-	"html/template"
 	"math/rand"
 	"reflect"
 	"testing"
@@ -24,27 +23,6 @@ import (
 	"golang.org/x/net/context"
 )
 
-type fakeCallInfo struct {
-	remoteAddr string
-	username   string
-}
-
-func (fci *fakeCallInfo) RemoteAddr() string {
-	return fci.remoteAddr
-}
-
-func (fci *fakeCallInfo) Username() string {
-	return fci.username
-}
-
-func (fci *fakeCallInfo) Text() string {
-	return ""
-}
-
-func (fci *fakeCallInfo) HTML() template.HTML {
-	return template.HTML("")
-}
-
 func TestQueryExecutorPlanDDL(t *testing.T) {
 	db := setUpQueryExecutorTest()
 	query := "alter table test_table add zipcode int"

go/vt/tabletserver/streamlogger.go → go/vt/tabletserver/sqlquery_stats.go

@@ -23,9 +23,12 @@ import (
 var SqlQueryLogger = streamlog.New("SqlQuery", 50)
 
 const (
-	QUERY_SOURCE_ROWCACHE = 1 << iota
-	QUERY_SOURCE_CONSOLIDATOR
-	QUERY_SOURCE_MYSQL
+	// QuerySourceRowcache means query result is found in rowcache.
+	QuerySourceRowcache = 1 << iota
+	// QuerySourceConsolidator means query result is found in consolidator.
+	QuerySourceConsolidator
+	// QuerySourceMySQL means query result is returned from MySQL.
+	QuerySourceMySQL
 )
 
 // SQLQueryStats records the stats for a single query
@@ -68,7 +71,7 @@ func (stats *SQLQueryStats) Send() {
 
 // AddRewrittenSql adds a single sql statement to the rewritten list
 func (stats *SQLQueryStats) AddRewrittenSql(sql string, start time.Time) {
-	stats.QuerySources |= QUERY_SOURCE_MYSQL
+	stats.QuerySources |= QuerySourceMySQL
 	stats.NumberOfQueries++
 	stats.rewrittenSqls = append(stats.rewrittenSqls, sql)
 	stats.MysqlResponseTime += time.Now().Sub(start)
@@ -140,15 +143,15 @@ func (stats *SQLQueryStats) FmtQuerySources() string {
 	}
 	sources := make([]string, 3)
 	n := 0
-	if stats.QuerySources&QUERY_SOURCE_MYSQL != 0 {
+	if stats.QuerySources&QuerySourceMySQL != 0 {
 		sources[n] = "mysql"
 		n++
 	}
-	if stats.QuerySources&QUERY_SOURCE_ROWCACHE != 0 {
+	if stats.QuerySources&QuerySourceRowcache != 0 {
 		sources[n] = "rowcache"
 		n++
 	}
-	if stats.QuerySources&QUERY_SOURCE_CONSOLIDATOR != 0 {
+	if stats.QuerySources&QuerySourceConsolidator != 0 {
 		sources[n] = "consolidator"
 		n++
 	}

go/vt/tabletserver/sqlquery_stats_test.go

@@ -0,0 +1,142 @@
+// Copyright 2015, Google Inc. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+package tabletserver
+
+import (
+	"fmt"
+	"net/url"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/youtube/vitess/go/sqltypes"
+	"github.com/youtube/vitess/go/vt/callinfo"
+	"golang.org/x/net/context"
+)
+
+func TestSqlQueryStats(t *testing.T) {
+	logStats := newSqlQueryStats("test", context.Background())
+	logStats.AddRewrittenSql("sql1", time.Now())
+
+	if !strings.Contains(logStats.RewrittenSql(), "sql1") {
+		t.Fatalf("RewrittenSql should contains sql: sql1")
+	}
+
+	if logStats.SizeOfResponse() != 0 {
+		t.Fatalf("there is no rows in log stats, estimated size should be 0 bytes")
+	}
+
+	logStats.Rows = [][]sqltypes.Value{[]sqltypes.Value{sqltypes.MakeString([]byte("a"))}}
+	if logStats.SizeOfResponse() <= 0 {
+		t.Fatalf("log stats has some rows, should have positive response size")
+	}
+
+	params := map[string][]string{"full": []string{}}
+
+	logStats.Format(url.Values(params))
+}
+
+func TestSqlQueryStatsFormatBindVariables(t *testing.T) {
+	logStats := newSqlQueryStats("test", context.Background())
+	logStats.BindVariables = make(map[string]interface{})
+	logStats.BindVariables["key_1"] = "val_1"
+	logStats.BindVariables["key_2"] = 789
+
+	formattedStr := logStats.FmtBindVariables(true)
+	if !strings.Contains(formattedStr, "key_1") ||
+		!strings.Contains(formattedStr, "val_1") {
+		t.Fatalf("bind variable 'key_1': 'val_1' is not formatted")
+	}
+	if !strings.Contains(formattedStr, "key_2") ||
+		!strings.Contains(formattedStr, "789") {
+		t.Fatalf("bind variable 'key_2': '789' is not formatted")
+	}
+
+	logStats.BindVariables["key_3"] = []byte("val_3")
+	formattedStr = logStats.FmtBindVariables(false)
+	if !strings.Contains(formattedStr, "key_1") {
+		t.Fatalf("bind variable 'key_1' is not formatted")
+	}
+	if !strings.Contains(formattedStr, "key_2") ||
+		!strings.Contains(formattedStr, "789") {
+		t.Fatalf("bind variable 'key_2': '789' is not formatted")
+	}
+	if !strings.Contains(formattedStr, "key_3") {
+		t.Fatalf("bind variable 'key_3' is not formatted")
+	}
+}
+
+func TestSqlQueryStatsFormatQuerySources(t *testing.T) {
+	logStats := newSqlQueryStats("test", context.Background())
+	if logStats.FmtQuerySources() != "none" {
+		t.Fatalf("should return none since log stats does not have any query source, but got: %s", logStats.FmtQuerySources())
+	}
+
+	logStats.QuerySources |= QuerySourceMySQL
+	if !strings.Contains(logStats.FmtQuerySources(), "mysql") {
+		t.Fatalf("'mysql' should be in formated query sources")
+	}
+
+	logStats.QuerySources |= QuerySourceRowcache
+	if !strings.Contains(logStats.FmtQuerySources(), "rowcache") {
+		t.Fatalf("'rowcache' should be in formated query sources")
+	}
+
+	logStats.QuerySources |= QuerySourceConsolidator
+	if !strings.Contains(logStats.FmtQuerySources(), "consolidator") {
+		t.Fatalf("'consolidator' should be in formated query sources")
+	}
+}
+
+func TestSqlQueryStatsContextHTML(t *testing.T) {
+	html := "HtmlContext"
+	callInfo := &fakeCallInfo{
+		html: html,
+	}
+	ctx := callinfo.NewContext(context.Background(), callInfo)
+	logStats := newSqlQueryStats("test", ctx)
+	if string(logStats.ContextHTML()) != html {
+		t.Fatalf("expect to get html: %s, but got: %s", html, string(logStats.ContextHTML()))
+	}
+}
+
+func TestSqlQueryStatsErrorStr(t *testing.T) {
+	logStats := newSqlQueryStats("test", context.Background())
+	if logStats.ErrorStr() != "" {
+		t.Fatalf("should not get error in stats, but got: %s", logStats.ErrorStr())
+	}
+	errStr := "unknown error"
+	logStats.Error = fmt.Errorf(errStr)
+	if logStats.ErrorStr() != errStr {
+		t.Fatalf("expect to get error string: %s, but got: %s", errStr, logStats.ErrorStr())
+	}
+}
+
+func TestSqlQueryStatsRemoteAddrUsername(t *testing.T) {
+	logStats := newSqlQueryStats("test", context.Background())
+	addr, user := logStats.RemoteAddrUsername()
+	if addr != "" {
+		t.Fatalf("remote addr should be empty")
+	}
+	if user != "" {
+		t.Fatalf("username should be empty")
+	}
+
+	remoteAddr := "1.2.3.4"
+	username := "vt"
+	callInfo := &fakeCallInfo{
+		remoteAddr: remoteAddr,
+		username:   username,
+	}
+	ctx := callinfo.NewContext(context.Background(), callInfo)
+	logStats = newSqlQueryStats("test", ctx)
+	addr, user = logStats.RemoteAddrUsername()
+	if addr != remoteAddr {
+		t.Fatalf("expected to get remote addr: %s, but got: %s", remoteAddr, addr)
+	}
+	if user != username {
+		t.Fatalf("expected to get username: %s, but got: %s", username, user)
+	}
+}

go/vt/tabletserver/testutils_test.go

@@ -0,0 +1,30 @@
+// Copyright 2015, Google Inc. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+package tabletserver
+
+import "html/template"
+
+type fakeCallInfo struct {
+	remoteAddr string
+	username   string
+	text       string
+	html       string
+}
+
+func (fci *fakeCallInfo) RemoteAddr() string {
+	return fci.remoteAddr
+}
+
+func (fci *fakeCallInfo) Username() string {
+	return fci.username
+}
+
+func (fci *fakeCallInfo) Text() string {
+	return fci.text
+}
+
+func (fci *fakeCallInfo) HTML() template.HTML {
+	return template.HTML(fci.html)
+}

go/vt/wrangler/keyspace.go

@@ -168,7 +168,7 @@ func (wr *Wrangler) MigrateServedTypes(ctx context.Context, keyspace, shard stri
 
 	// rebuild the keyspace serving graph if there was no error
 	if !rec.HasErrors() {
-		rec.RecordError(wr.RebuildKeyspaceGraph(ctx, keyspace, nil))
+		rec.RecordError(wr.RebuildKeyspaceGraph(ctx, keyspace, cells))
 	}
 
 	// Send a refresh to the tablets we just disabled, iff: