func (s *AnalyzerTestSuite) TestRunMockWorker(t *C) {
a := qan.NewRealAnalyzer(
pct.NewLogger(s.logChan, "qan-analyzer"),
s.config,
s.iter,
s.nullmysql,
s.restartChan,
s.worker,
s.clock,
s.spool,
)
err := a.Start()
t.Assert(err, IsNil)
test.WaitStatus(1, a, "qan-analyzer", "Idle")
// No interval yet, so work should not have one.
t.Check(s.worker.Interval, IsNil)
// Send an interval. The analyzer runs the worker with it.
now := time.Now()
i := &qan.Interval{
Number: 1,
StartTime: now,
StopTime: now.Add(1 * time.Minute),
Filename: "slow.log",
StartOffset: 0,
EndOffset: 999,
}
s.intervalChan <- i
if !test.WaitState(s.worker.SetupChan) {
t.Fatal("Timeout waiting for <-s.worker.SetupChan")
}
t.Check(s.worker.Interval, DeepEquals, i)
if !test.WaitState(s.worker.RunChan) {
t.Fatal("Timeout waiting for <-s.worker.SetupChan")
}
if !test.WaitState(s.worker.CleanupChan) {
t.Fatal("Timeout waiting for <-s.worker.SetupChan")
}
err = a.Stop()
t.Assert(err, IsNil)
test.WaitStatus(1, a, "qan-analyzer", "Stopped")
t.Check(a.String(), Equals, "qan-analyzer")
}
func (s *ManagerTestSuite) TestStartWithConfig(t *C) {
for _, analyzerType := range []string{"slowlog", "perfschema"} {
// Make a qan.Manager with mock factories.
mockConnFactory := &mock.ConnectionFactory{Conn: s.nullmysql}
a := mock.NewQanAnalyzer()
f := mock.NewQanAnalyzerFactory(a)
m := qan.NewManager(s.logger, s.clock, s.im, s.mrmsMonitor, mockConnFactory, f)
t.Assert(m, NotNil)
// Write a realistic qan.conf config to disk.
config := qan.Config{
ServiceInstance: s.mysqlInstance,
CollectFrom: analyzerType,
Interval: 300,
MaxWorkers: 1,
WorkerRunTime: 600,
Start: []mysql.Query{
mysql.Query{Set: "SET GLOBAL slow_query_log=OFF"},
mysql.Query{Set: "SET GLOBAL long_query_time=0.456"},
mysql.Query{Set: "SET GLOBAL slow_query_log=ON"},
},
Stop: []mysql.Query{
mysql.Query{Set: "SET GLOBAL slow_query_log=OFF"},
mysql.Query{Set: "SET GLOBAL long_query_time=10"},
},
}
err := pct.Basedir.WriteConfig("qan", &config)
t.Assert(err, IsNil)
// qan.Start() reads qan.conf from disk and starts an analyzer for it.
err = m.Start()
t.Check(err, IsNil)
// Wait until qan.Start() calls analyzer.Start().
if !test.WaitState(a.StartChan) {
t.Fatal("Timeout waiting for <-a.StartChan")
}
// After starting, the manager's status should be Running and the analyzer's
// status should be reported too.
status := m.Status()
t.Check(status["qan"], Equals, "Running")
t.Check(status["qan-analyzer"], Equals, "ok")
// Check the args passed by the manager to the analyzer factory.
if len(f.Args) == 0 {
t.Error("len(f.Args) == 0, expected 1")
} else {
t.Check(f.Args, HasLen, 1)
t.Check(f.Args[0].Config, DeepEquals, config)
t.Check(f.Args[0].Name, Equals, "qan-analyzer")
}
// qan.Stop() stops the analyzer and leaves qan.conf on disk.
err = m.Stop()
t.Assert(err, IsNil)
// Wait until qan.Stop() calls analyzer.Stop().
if !test.WaitState(a.StopChan) {
t.Fatal("Timeout waiting for <-a.StopChan")
}
// qan.conf still exists after qan.Stop().
t.Check(test.FileExists(pct.Basedir.ConfigFile("qan")), Equals, true)
// The analyzer is no longer reported in the status because it was stopped
// and removed when the manager was stopped.
status = m.Status()
t.Check(status["qan"], Equals, "Stopped")
}
}
func (s *AnalyzerTestSuite) TestRecoverWorkerPanic(t *C) {
a := qan.NewRealAnalyzer(
pct.NewLogger(s.logChan, "qan-analyzer"),
s.config,
s.iter,
s.nullmysql,
s.restartChan,
s.worker,
s.clock,
s.spool,
)
err := a.Start()
t.Assert(err, IsNil)
test.WaitStatus(1, a, "qan-analyzer", "Idle")
// This will cause the worker to panic when it's ran by the analyzer.
s.worker.SetupCrashChan <- true
// Send an interval. The analyzer runs the worker with it.
now := time.Now()
i := &qan.Interval{
Number: 1,
StartTime: now,
StopTime: now.Add(1 * time.Minute),
Filename: "slow.log",
StartOffset: 0,
EndOffset: 999,
}
s.intervalChan <- i
if !test.WaitState(s.worker.SetupChan) {
t.Fatal("Timeout waiting for <-s.worker.SetupChan")
}
// Wait for that ^ run of the worker to fully stop and return.
test.WaitStatus(1, a, "qan-analyzer", "Idle")
i = &qan.Interval{
Number: 2,
StartTime: now,
StopTime: now.Add(1 * time.Minute),
Filename: "slow.log",
StartOffset: 1000,
EndOffset: 2000,
}
s.intervalChan <- i
if !test.WaitState(s.worker.SetupChan) {
t.Fatal("Timeout waiting for <-s.worker.SetupChan")
}
t.Check(s.worker.Interval, DeepEquals, i)
if !test.WaitState(s.worker.RunChan) {
t.Fatal("Timeout waiting for <-s.worker.SetupChan")
}
if !test.WaitState(s.worker.CleanupChan) {
t.Fatal("Timeout waiting for <-s.worker.SetupChan")
}
err = a.Stop()
t.Assert(err, IsNil)
test.WaitStatus(1, a, "qan-analyzer", "Stopped")
t.Check(a.String(), Equals, "qan-analyzer")
}
func (s *AnalyzerTestSuite) TestMySQLRestart(t *C) {
a := qan.NewRealAnalyzer(
pct.NewLogger(s.logChan, "qan-analyzer"),
s.config,
s.iter,
s.nullmysql,
s.restartChan,
s.worker,
s.clock,
s.spool,
)
err := a.Start()
t.Assert(err, IsNil)
test.WaitStatus(1, a, "qan-analyzer", "Idle")
// When analyzer starts, it configures MySQL using the Start set of queries.
got := s.nullmysql.GetSet()
expect := s.config.Start
if same, diff := IsDeeply(got, expect); !same {
Dump(got)
t.Error(diff)
}
// Analyzer starts its iter when MySQL is ready.
t.Check(s.iter.Calls(), DeepEquals, []string{"Start"})
s.iter.Reset()
// Simulate a MySQL restart. This causes the analyzer to re-configure MySQL
// using the same Start queries.
s.nullmysql.Reset()
s.restartChan <- true
if !test.WaitState(s.nullmysql.SetChan) {
t.Error("Timeout waiting for <-s.nullmysql.SetChan")
}
test.WaitStatus(1, a, "qan-analyzer", "Idle")
got = s.nullmysql.GetSet()
if same, diff := IsDeeply(got, expect); !same {
Dump(got)
t.Error(diff)
}
// Analyzer stops and re-starts its iter on MySQL restart.
t.Check(s.iter.Calls(), DeepEquals, []string{"Stop", "Start"})
s.nullmysql.Reset()
// Enable slowlog DB rotation by setting max_slowlog_size to a value > 4096 and simulate MySQL restart
s.nullmysql.SetGlobalVarNumber("max_slowlog_size", 100000)
s.restartChan <- true
if !test.WaitState(s.nullmysql.SetChan) {
t.Error("Timeout waiting for <-s.nullmysql.SetChan")
}
test.WaitStatus(1, a, "qan-analyzer", "Idle")
expectedQueries := []mysql.Query{
mysql.Query{
Set: "SET GLOBAL max_slowlog_size = 0",
Verify: "",
Expect: "",
},
mysql.Query{
Set: "-- start",
Verify: "",
Expect: "",
},
}
t.Check(s.nullmysql.GetSet(), DeepEquals, expectedQueries)
t.Check(a.Config().MaxSlowLogSize, Equals, int64(100000))
err = a.Stop()
t.Assert(err, IsNil)
}
func (s *WorkerTestSuite) TestStop(t *C) {
config := qan.Config{
ServiceInstance: s.mysqlInstance,
Interval: 300,
MaxSlowLogSize: 1024 * 1024 * 1024,
RemoveOldSlowLogs: true,
WorkerRunTime: 60,
Start: []mysql.Query{},
Stop: []mysql.Query{},
CollectFrom: "slowlog",
}
w := slowlog.NewWorker(s.logger, config, s.nullmysql)
// Make and set a mock log.LogParser. The worker will use this once when
// Start() is called instead of making a real slow log parser.
p := mock.NewLogParser()
w.SetLogParser(p)
now := time.Now()
i := &qan.Interval{
Number: 1,
StartTime: now,
StopTime: now.Add(1 * time.Minute),
Filename: inputDir + "slow006.log",
StartOffset: 0,
EndOffset: 100000,
}
w.Setup(i)
// Run the worker. It calls p.Start() and p.Stop() when done.
doneChan := make(chan bool, 1)
var res *qan.Result
var err error
go func() {
res, err = w.Run() // calls p.Start()
doneChan <- true
}()
// Send first event. This is aggregated.
e := &log.Event{
Offset: 0,
Ts: "071015 21:45:10",
Query: "select 1 from t",
Db: "db1",
TimeMetrics: map[string]float32{
"Query_time": 1.111,
},
}
p.Send(e) // blocks until received
// This will block until we send a 2nd event...
stopChan := make(chan bool, 1)
go func() {
w.Stop()
stopChan <- true
}()
// Give Stop() time to send its signal. This isn't ideal, but it's necessary.
time.Sleep(500 * time.Millisecond)
// Send 2nd event which is not aggregated because a stop ^ is pending.
e = &log.Event{
Offset: 100,
Ts: "071015 21:50:10",
Query: "select 2 from u",
Db: "db2",
TimeMetrics: map[string]float32{
"Query_time": 2.222,
},
}
p.Send(e) // blocks until received
// Side test: Status()
status := w.Status()
t.Check(strings.HasPrefix(status["qan-worker"], "Parsing "+i.Filename), Equals, true)
if !test.WaitState(stopChan) {
t.Fatal("Timeout waiting for <-stopChan")
}
if !test.WaitState(doneChan) {
t.Fatal("Timeout waiting for <-doneChan")
}
t.Check(res.Global.TotalQueries, Equals, uint64(1))
t.Check(res.Class, HasLen, 1)
}