more logging and diagnostics for schema reloads

go/vt/tabletserver/schema_info.go

@@ -155,6 +155,7 @@ func (si *SchemaInfo) Reload() {
 		relog.Warning("Could not get table list for reload: %v", err)
 		return
 	}
+	relog.Info("Reloading schema")
 	for _, row := range tables.Rows {
 		tableName := row[0].String()
 		si.updateLastChange(row[2])

go/vt/tabletserver/sqlquery.go

@@ -381,6 +381,7 @@ func (sq *SqlQuery) statsJSON() string {
 	fmt.Fprintf(buf, "\n \"States\": %v,", sq.states.String())
 	fmt.Fprintf(buf, "\n \"CachePool\": %v,", sq.qe.cachePool.StatsJSON())
 	fmt.Fprintf(buf, "\n \"QueryCache\": %v,", sq.qe.schemaInfo.queries.StatsJSON())
+	fmt.Fprintf(buf, "\n \"SchemaReloadTime\": %v,", int64(sq.qe.schemaInfo.reloadTime))
 	fmt.Fprintf(buf, "\n \"ConnPool\": %v,", sq.qe.connPool.StatsJSON())
 	fmt.Fprintf(buf, "\n \"StreamConnPool\": %v,", sq.qe.streamConnPool.StatsJSON())
 	fmt.Fprintf(buf, "\n \"TxPool\": %v,", sq.qe.txPool.StatsJSON())

test/queryservice_tests/nocache_tests.py

@@ -207,10 +207,14 @@ class TestNocache(framework.TestCase):
     self.assertEqual(vend.Voltron.QueryCache.Capacity, 5000)
 
   def test_schema_reload_time(self):
+    vend = self.env.debug_vars()
+    self.assertEqual(vend.Voltron.SchemaReloadTime, 1800 * 1e9)
     mcu = self.env.mysql_conn.cursor()
     mcu.execute("create table vtocc_temp(intval int)")
     # This should cause a reload
     self.env.execute("set vt_schema_reload_time=600")
+    vend = self.env.debug_vars()
+    self.assertEqual(vend.Voltron.SchemaReloadTime, 600 * 1e9)
     try:
       for i in range(10):
         try: