github.com/whtcorpsinc/MilevaDB-Prod@v0.0.0-20211104133533-f57f4be3b597/interlock/memtable_reader_test.go (about) 1 // Copyright 2020 WHTCORPS INC, Inc. 2 // 3 // Licensed under the Apache License, Version 2.0 (the "License"); 4 // you may not use this file except in compliance with the License. 5 // You may obtain a copy of the License at 6 // 7 // http://www.apache.org/licenses/LICENSE-2.0 8 // 9 // Unless required by applicable law or agreed to in writing, software 10 // distributed under the License is distributed on an "AS IS" BASIS, 11 // See the License for the specific language governing permissions and 12 // limitations under the License. 13 14 package interlock_test 15 16 import ( 17 "context" 18 "fmt" 19 "io/ioutil" 20 "log" 21 "net" 22 "net/http/httptest" 23 "os" 24 "path/filepath" 25 "strings" 26 "sync/atomic" 27 "time" 28 29 "github.com/gorilla/mux" 30 pperceptron "github.com/prometheus/common/perceptron" 31 . "github.com/whtcorpsinc/check" 32 "github.com/whtcorpsinc/ekvproto/pkg/diagnosticspb" 33 "github.com/whtcorpsinc/failpoint" 34 "github.com/whtcorpsinc/fn" 35 "github.com/whtcorpsinc/milevadb/ekv" 36 "github.com/whtcorpsinc/milevadb/petri" 37 "github.com/whtcorpsinc/milevadb/soliton/FIDelapi" 38 "github.com/whtcorpsinc/milevadb/soliton/testkit" 39 "github.com/whtcorpsinc/milevadb/stochastik" 40 "github.com/whtcorpsinc/sysutil" 41 "google.golang.org/grpc" 42 ) 43 44 type testMemBlockReaderSuite struct{ *testClusterBlockBase } 45 46 type testClusterBlockBase struct { 47 causetstore ekv.CausetStorage 48 dom *petri.Petri 49 } 50 51 func (s *testClusterBlockBase) SetUpSuite(c *C) { 52 causetstore, dom, err := newStoreWithBootstrap() 53 c.Assert(err, IsNil) 54 s.causetstore = causetstore 55 s.dom = dom 56 } 57 58 func (s *testClusterBlockBase) TearDownSuite(c *C) { 59 s.dom.Close() 60 s.causetstore.Close() 61 } 62 63 func (s *testMemBlockReaderSuite) TestMetricBlockData(c *C) { 64 fpName := "github.com/whtcorpsinc/milevadb/interlock/mockMetricsPromData" 65 c.Assert(failpoint.Enable(fpName, "return"), IsNil) 66 defer func() { c.Assert(failpoint.Disable(fpName), IsNil) }() 67 68 // mock prometheus data 69 matrix := pperceptron.Matrix{} 70 metric := map[pperceptron.LabelName]pperceptron.LabelValue{ 71 "instance": "127.0.0.1:10080", 72 } 73 t, err := time.ParseInLocation("2006-01-02 15:04:05.999", "2020-12-23 20:11:35", time.Local) 74 c.Assert(err, IsNil) 75 v1 := pperceptron.SamplePair{ 76 Timestamp: pperceptron.Time(t.UnixNano() / int64(time.Millisecond)), 77 Value: pperceptron.SampleValue(0.1), 78 } 79 matrix = append(matrix, &pperceptron.SampleStream{Metric: metric, Values: []pperceptron.SamplePair{v1}}) 80 81 ctx := context.WithValue(context.Background(), "__mockMetricsPromData", matrix) 82 ctx = failpoint.WithHook(ctx, func(ctx context.Context, fpname string) bool { 83 return fpname == fpName 84 }) 85 86 tk := testkit.NewTestKit(c, s.causetstore) 87 tk.MustInterDirc("use metrics_schema") 88 89 cases := []struct { 90 allegrosql string 91 exp []string 92 }{ 93 { 94 allegrosql: "select time,instance,quantile,value from milevadb_query_duration;", 95 exp: []string{ 96 "2020-12-23 20:11:35.000000 127.0.0.1:10080 0.9 0.1", 97 }, 98 }, 99 { 100 allegrosql: "select time,instance,quantile,value from milevadb_query_duration where quantile in (0.85, 0.95);", 101 exp: []string{ 102 "2020-12-23 20:11:35.000000 127.0.0.1:10080 0.85 0.1", 103 "2020-12-23 20:11:35.000000 127.0.0.1:10080 0.95 0.1", 104 }, 105 }, 106 { 107 allegrosql: "select time,instance,quantile,value from milevadb_query_duration where quantile=0.5", 108 exp: []string{ 109 "2020-12-23 20:11:35.000000 127.0.0.1:10080 0.5 0.1", 110 }, 111 }, 112 } 113 114 for _, cas := range cases { 115 rs, err := tk.Se.InterDircute(ctx, cas.allegrosql) 116 c.Assert(err, IsNil) 117 result := tk.ResultSetToResultWithCtx(ctx, rs[0], Commentf("allegrosql: %s", cas.allegrosql)) 118 result.Check(testkit.Events(cas.exp...)) 119 } 120 } 121 122 func (s *testMemBlockReaderSuite) TestMilevaDBClusterConfig(c *C) { 123 // mock FIDel http server 124 router := mux.NewRouter() 125 126 type mockServer struct { 127 address string 128 server *httptest.Server 129 } 130 const testServerCount = 3 131 var testServers []*mockServer 132 for i := 0; i < testServerCount; i++ { 133 server := httptest.NewServer(router) 134 address := strings.TrimPrefix(server.URL, "http://") 135 testServers = append(testServers, &mockServer{ 136 address: address, 137 server: server, 138 }) 139 } 140 defer func() { 141 for _, server := range testServers { 142 server.server.Close() 143 } 144 }() 145 146 // We check the counter to valid how many times request has been sent 147 var requestCounter int32 148 var mockConfig = func() (map[string]interface{}, error) { 149 atomic.AddInt32(&requestCounter, 1) 150 configuration := map[string]interface{}{ 151 "key1": "value1", 152 "key2": map[string]string{ 153 "nest1": "n-value1", 154 "nest2": "n-value2", 155 }, 156 } 157 return configuration, nil 158 } 159 160 // fidel config 161 router.Handle(FIDelapi.Config, fn.Wrap(mockConfig)) 162 // MilevaDB/EinsteinDB config 163 router.Handle("/config", fn.Wrap(mockConfig)) 164 165 // mock servers 166 servers := []string{} 167 for _, typ := range []string{"milevadb", "einsteindb", "fidel"} { 168 for _, server := range testServers { 169 servers = append(servers, strings.Join([]string{typ, server.address, server.address}, ",")) 170 } 171 } 172 173 fpName := "github.com/whtcorpsinc/milevadb/interlock/mockClusterConfigServerInfo" 174 fpExpr := strings.Join(servers, ";") 175 c.Assert(failpoint.Enable(fpName, fmt.Sprintf(`return("%s")`, fpExpr)), IsNil) 176 defer func() { c.Assert(failpoint.Disable(fpName), IsNil) }() 177 178 tk := testkit.NewTestKit(c, s.causetstore) 179 tk.MustQuery("select type, `key`, value from information_schema.cluster_config").Check(testkit.Events( 180 "milevadb key1 value1", 181 "milevadb key2.nest1 n-value1", 182 "milevadb key2.nest2 n-value2", 183 "milevadb key1 value1", 184 "milevadb key2.nest1 n-value1", 185 "milevadb key2.nest2 n-value2", 186 "milevadb key1 value1", 187 "milevadb key2.nest1 n-value1", 188 "milevadb key2.nest2 n-value2", 189 "einsteindb key1 value1", 190 "einsteindb key2.nest1 n-value1", 191 "einsteindb key2.nest2 n-value2", 192 "einsteindb key1 value1", 193 "einsteindb key2.nest1 n-value1", 194 "einsteindb key2.nest2 n-value2", 195 "einsteindb key1 value1", 196 "einsteindb key2.nest1 n-value1", 197 "einsteindb key2.nest2 n-value2", 198 "fidel key1 value1", 199 "fidel key2.nest1 n-value1", 200 "fidel key2.nest2 n-value2", 201 "fidel key1 value1", 202 "fidel key2.nest1 n-value1", 203 "fidel key2.nest2 n-value2", 204 "fidel key1 value1", 205 "fidel key2.nest1 n-value1", 206 "fidel key2.nest2 n-value2", 207 )) 208 warnings := tk.Se.GetStochastikVars().StmtCtx.GetWarnings() 209 c.Assert(len(warnings), Equals, 0, Commentf("unexpected warnigns: %+v", warnings)) 210 c.Assert(requestCounter, Equals, int32(9)) 211 212 // type => server index => event 213 rows := map[string][][]string{} 214 for _, typ := range []string{"milevadb", "einsteindb", "fidel"} { 215 for _, server := range testServers { 216 rows[typ] = append(rows[typ], []string{ 217 fmt.Sprintf("%s %s key1 value1", typ, server.address), 218 fmt.Sprintf("%s %s key2.nest1 n-value1", typ, server.address), 219 fmt.Sprintf("%s %s key2.nest2 n-value2", typ, server.address), 220 }) 221 } 222 } 223 var flatten = func(ss ...[]string) []string { 224 var result []string 225 for _, xs := range ss { 226 result = append(result, xs...) 227 } 228 return result 229 } 230 var cases = []struct { 231 allegrosql string 232 reqCount int32 233 rows []string 234 }{ 235 { 236 allegrosql: "select * from information_schema.cluster_config", 237 reqCount: 9, 238 rows: flatten( 239 rows["milevadb"][0], 240 rows["milevadb"][1], 241 rows["milevadb"][2], 242 rows["einsteindb"][0], 243 rows["einsteindb"][1], 244 rows["einsteindb"][2], 245 rows["fidel"][0], 246 rows["fidel"][1], 247 rows["fidel"][2], 248 ), 249 }, 250 { 251 allegrosql: "select * from information_schema.cluster_config where type='fidel' or type='einsteindb'", 252 reqCount: 6, 253 rows: flatten( 254 rows["einsteindb"][0], 255 rows["einsteindb"][1], 256 rows["einsteindb"][2], 257 rows["fidel"][0], 258 rows["fidel"][1], 259 rows["fidel"][2], 260 ), 261 }, 262 { 263 allegrosql: "select * from information_schema.cluster_config where type='fidel' or instance='" + testServers[0].address + "'", 264 reqCount: 9, 265 rows: flatten( 266 rows["milevadb"][0], 267 rows["einsteindb"][0], 268 rows["fidel"][0], 269 rows["fidel"][1], 270 rows["fidel"][2], 271 ), 272 }, 273 { 274 allegrosql: "select * from information_schema.cluster_config where type='fidel' and type='einsteindb'", 275 reqCount: 0, 276 }, 277 { 278 allegrosql: "select * from information_schema.cluster_config where type='einsteindb'", 279 reqCount: 3, 280 rows: flatten( 281 rows["einsteindb"][0], 282 rows["einsteindb"][1], 283 rows["einsteindb"][2], 284 ), 285 }, 286 { 287 allegrosql: "select * from information_schema.cluster_config where type='fidel'", 288 reqCount: 3, 289 rows: flatten( 290 rows["fidel"][0], 291 rows["fidel"][1], 292 rows["fidel"][2], 293 ), 294 }, 295 { 296 allegrosql: "select * from information_schema.cluster_config where type='milevadb'", 297 reqCount: 3, 298 rows: flatten( 299 rows["milevadb"][0], 300 rows["milevadb"][1], 301 rows["milevadb"][2], 302 ), 303 }, 304 { 305 allegrosql: "select * from information_schema.cluster_config where 'milevadb'=type", 306 reqCount: 3, 307 rows: flatten( 308 rows["milevadb"][0], 309 rows["milevadb"][1], 310 rows["milevadb"][2], 311 ), 312 }, 313 { 314 allegrosql: "select * from information_schema.cluster_config where type in ('milevadb', 'einsteindb')", 315 reqCount: 6, 316 rows: flatten( 317 rows["milevadb"][0], 318 rows["milevadb"][1], 319 rows["milevadb"][2], 320 rows["einsteindb"][0], 321 rows["einsteindb"][1], 322 rows["einsteindb"][2], 323 ), 324 }, 325 { 326 allegrosql: "select * from information_schema.cluster_config where type in ('milevadb', 'einsteindb', 'fidel')", 327 reqCount: 9, 328 rows: flatten( 329 rows["milevadb"][0], 330 rows["milevadb"][1], 331 rows["milevadb"][2], 332 rows["einsteindb"][0], 333 rows["einsteindb"][1], 334 rows["einsteindb"][2], 335 rows["fidel"][0], 336 rows["fidel"][1], 337 rows["fidel"][2], 338 ), 339 }, 340 { 341 allegrosql: fmt.Sprintf(`select * from information_schema.cluster_config where instance='%s'`, 342 testServers[0].address), 343 reqCount: 3, 344 rows: flatten( 345 rows["milevadb"][0], 346 rows["einsteindb"][0], 347 rows["fidel"][0], 348 ), 349 }, 350 { 351 allegrosql: fmt.Sprintf(`select * from information_schema.cluster_config where type='milevadb' and instance='%s'`, 352 testServers[0].address), 353 reqCount: 1, 354 rows: flatten( 355 rows["milevadb"][0], 356 ), 357 }, 358 { 359 allegrosql: fmt.Sprintf(`select * from information_schema.cluster_config where type in ('milevadb', 'einsteindb') and instance='%s'`, 360 testServers[0].address), 361 reqCount: 2, 362 rows: flatten( 363 rows["milevadb"][0], 364 rows["einsteindb"][0], 365 ), 366 }, 367 { 368 allegrosql: fmt.Sprintf(`select * from information_schema.cluster_config where type in ('milevadb', 'einsteindb') and instance in ('%s', '%s')`, 369 testServers[0].address, testServers[0].address), 370 reqCount: 2, 371 rows: flatten( 372 rows["milevadb"][0], 373 rows["einsteindb"][0], 374 ), 375 }, 376 { 377 allegrosql: fmt.Sprintf(`select * from information_schema.cluster_config where type in ('milevadb', 'einsteindb') and instance in ('%s', '%s')`, 378 testServers[0].address, testServers[1].address), 379 reqCount: 4, 380 rows: flatten( 381 rows["milevadb"][0], 382 rows["milevadb"][1], 383 rows["einsteindb"][0], 384 rows["einsteindb"][1], 385 ), 386 }, 387 { 388 allegrosql: fmt.Sprintf(`select * from information_schema.cluster_config where type in ('milevadb', 'einsteindb') and type='fidel' and instance in ('%s', '%s')`, 389 testServers[0].address, testServers[1].address), 390 reqCount: 0, 391 }, 392 { 393 allegrosql: fmt.Sprintf(`select * from information_schema.cluster_config where type in ('milevadb', 'einsteindb') and instance in ('%s', '%s') and instance='%s'`, 394 testServers[0].address, testServers[1].address, testServers[2].address), 395 reqCount: 0, 396 }, 397 { 398 allegrosql: fmt.Sprintf(`select * from information_schema.cluster_config where type in ('milevadb', 'einsteindb') and instance in ('%s', '%s') and instance='%s'`, 399 testServers[0].address, testServers[1].address, testServers[0].address), 400 reqCount: 2, 401 rows: flatten( 402 rows["milevadb"][0], 403 rows["einsteindb"][0], 404 ), 405 }, 406 } 407 408 for _, ca := range cases { 409 // reset the request counter 410 requestCounter = 0 411 tk.MustQuery(ca.allegrosql).Check(testkit.Events(ca.rows...)) 412 warnings := tk.Se.GetStochastikVars().StmtCtx.GetWarnings() 413 c.Assert(len(warnings), Equals, 0, Commentf("unexpected warnigns: %+v", warnings)) 414 c.Assert(requestCounter, Equals, ca.reqCount, Commentf("ALLEGROALLEGROSQL: %s", ca.allegrosql)) 415 } 416 } 417 418 func (s *testClusterBlockBase) writeTmpFile(c *C, dir, filename string, lines []string) { 419 err := ioutil.WriteFile(filepath.Join(dir, filename), []byte(strings.Join(lines, "\n")), os.ModePerm) 420 c.Assert(err, IsNil, Commentf("write tmp file %s failed", filename)) 421 } 422 423 type testServer struct { 424 typ string 425 server *grpc.Server 426 address string 427 tmFIDelir string 428 logFile string 429 } 430 431 func (s *testClusterBlockBase) setupClusterGRPCServer(c *C) map[string]*testServer { 432 // tp => testServer 433 testServers := map[string]*testServer{} 434 435 // create gRPC servers 436 for _, typ := range []string{"milevadb", "einsteindb", "fidel"} { 437 tmFIDelir, err := ioutil.TemFIDelir("", typ) 438 c.Assert(err, IsNil) 439 440 server := grpc.NewServer() 441 logFile := filepath.Join(tmFIDelir, fmt.Sprintf("%s.log", typ)) 442 diagnosticspb.RegisterDiagnosticsServer(server, sysutil.NewDiagnosticsServer(logFile)) 443 444 // Find a available port 445 listener, err := net.Listen("tcp", "127.0.0.1:0") 446 c.Assert(err, IsNil, Commentf("cannot find available port")) 447 448 testServers[typ] = &testServer{ 449 typ: typ, 450 server: server, 451 address: fmt.Sprintf("127.0.0.1:%d", listener.Addr().(*net.TCPAddr).Port), 452 tmFIDelir: tmFIDelir, 453 logFile: logFile, 454 } 455 go func() { 456 if err := server.Serve(listener); err != nil { 457 log.Fatalf("failed to serve: %v", err) 458 } 459 }() 460 } 461 return testServers 462 } 463 464 func (s *testMemBlockReaderSuite) TestMilevaDBClusterLog(c *C) { 465 testServers := s.setupClusterGRPCServer(c) 466 defer func() { 467 for _, s := range testServers { 468 s.server.Stop() 469 c.Assert(os.RemoveAll(s.tmFIDelir), IsNil, Commentf("remove tmFIDelir %v failed", s.tmFIDelir)) 470 } 471 }() 472 473 // time format of log file 474 var logtime = func(s string) string { 475 t, err := time.ParseInLocation("2006/01/02 15:04:05.000", s, time.Local) 476 c.Assert(err, IsNil) 477 return t.Format("[2006/01/02 15:04:05.000 -07:00]") 478 } 479 480 // time format of query output 481 var restime = func(s string) string { 482 t, err := time.ParseInLocation("2006/01/02 15:04:05.000", s, time.Local) 483 c.Assert(err, IsNil) 484 return t.Format("2006/01/02 15:04:05.000") 485 } 486 487 // prepare log files 488 // MilevaDB 489 s.writeTmpFile(c, testServers["milevadb"].tmFIDelir, "milevadb.log", []string{ 490 logtime(`2020/08/26 06:19:13.011`) + ` [INFO] [test log message milevadb 1, foo]`, 491 logtime(`2020/08/26 06:19:14.011`) + ` [DEBUG] [test log message milevadb 2, foo]`, 492 logtime(`2020/08/26 06:19:15.011`) + ` [error] [test log message milevadb 3, foo]`, 493 logtime(`2020/08/26 06:19:16.011`) + ` [trace] [test log message milevadb 4, foo]`, 494 logtime(`2020/08/26 06:19:17.011`) + ` [CRITICAL] [test log message milevadb 5, foo]`, 495 }) 496 s.writeTmpFile(c, testServers["milevadb"].tmFIDelir, "milevadb-1.log", []string{ 497 logtime(`2020/08/26 06:25:13.011`) + ` [info] [test log message milevadb 10, bar]`, 498 logtime(`2020/08/26 06:25:14.011`) + ` [debug] [test log message milevadb 11, bar]`, 499 logtime(`2020/08/26 06:25:15.011`) + ` [ERROR] [test log message milevadb 12, bar]`, 500 logtime(`2020/08/26 06:25:16.011`) + ` [TRACE] [test log message milevadb 13, bar]`, 501 logtime(`2020/08/26 06:25:17.011`) + ` [critical] [test log message milevadb 14, bar]`, 502 }) 503 504 // EinsteinDB 505 s.writeTmpFile(c, testServers["einsteindb"].tmFIDelir, "einsteindb.log", []string{ 506 logtime(`2020/08/26 06:19:13.011`) + ` [INFO] [test log message einsteindb 1, foo]`, 507 logtime(`2020/08/26 06:20:14.011`) + ` [DEBUG] [test log message einsteindb 2, foo]`, 508 logtime(`2020/08/26 06:21:15.011`) + ` [error] [test log message einsteindb 3, foo]`, 509 logtime(`2020/08/26 06:22:16.011`) + ` [trace] [test log message einsteindb 4, foo]`, 510 logtime(`2020/08/26 06:23:17.011`) + ` [CRITICAL] [test log message einsteindb 5, foo]`, 511 }) 512 s.writeTmpFile(c, testServers["einsteindb"].tmFIDelir, "einsteindb-1.log", []string{ 513 logtime(`2020/08/26 06:24:15.011`) + ` [info] [test log message einsteindb 10, bar]`, 514 logtime(`2020/08/26 06:25:16.011`) + ` [debug] [test log message einsteindb 11, bar]`, 515 logtime(`2020/08/26 06:26:17.011`) + ` [ERROR] [test log message einsteindb 12, bar]`, 516 logtime(`2020/08/26 06:27:18.011`) + ` [TRACE] [test log message einsteindb 13, bar]`, 517 logtime(`2020/08/26 06:28:19.011`) + ` [critical] [test log message einsteindb 14, bar]`, 518 }) 519 520 // FIDel 521 s.writeTmpFile(c, testServers["fidel"].tmFIDelir, "fidel.log", []string{ 522 logtime(`2020/08/26 06:18:13.011`) + ` [INFO] [test log message fidel 1, foo]`, 523 logtime(`2020/08/26 06:19:14.011`) + ` [DEBUG] [test log message fidel 2, foo]`, 524 logtime(`2020/08/26 06:20:15.011`) + ` [error] [test log message fidel 3, foo]`, 525 logtime(`2020/08/26 06:21:16.011`) + ` [trace] [test log message fidel 4, foo]`, 526 logtime(`2020/08/26 06:22:17.011`) + ` [CRITICAL] [test log message fidel 5, foo]`, 527 }) 528 s.writeTmpFile(c, testServers["fidel"].tmFIDelir, "fidel-1.log", []string{ 529 logtime(`2020/08/26 06:23:13.011`) + ` [info] [test log message fidel 10, bar]`, 530 logtime(`2020/08/26 06:24:14.011`) + ` [debug] [test log message fidel 11, bar]`, 531 logtime(`2020/08/26 06:25:15.011`) + ` [ERROR] [test log message fidel 12, bar]`, 532 logtime(`2020/08/26 06:26:16.011`) + ` [TRACE] [test log message fidel 13, bar]`, 533 logtime(`2020/08/26 06:27:17.011`) + ` [critical] [test log message fidel 14, bar]`, 534 }) 535 536 fullLogs := [][]string{ 537 {"2020/08/26 06:18:13.011", "fidel", "INFO", "[test log message fidel 1, foo]"}, 538 {"2020/08/26 06:19:13.011", "milevadb", "INFO", "[test log message milevadb 1, foo]"}, 539 {"2020/08/26 06:19:13.011", "einsteindb", "INFO", "[test log message einsteindb 1, foo]"}, 540 {"2020/08/26 06:19:14.011", "fidel", "DEBUG", "[test log message fidel 2, foo]"}, 541 {"2020/08/26 06:19:14.011", "milevadb", "DEBUG", "[test log message milevadb 2, foo]"}, 542 {"2020/08/26 06:19:15.011", "milevadb", "error", "[test log message milevadb 3, foo]"}, 543 {"2020/08/26 06:19:16.011", "milevadb", "trace", "[test log message milevadb 4, foo]"}, 544 {"2020/08/26 06:19:17.011", "milevadb", "CRITICAL", "[test log message milevadb 5, foo]"}, 545 {"2020/08/26 06:20:14.011", "einsteindb", "DEBUG", "[test log message einsteindb 2, foo]"}, 546 {"2020/08/26 06:20:15.011", "fidel", "error", "[test log message fidel 3, foo]"}, 547 {"2020/08/26 06:21:15.011", "einsteindb", "error", "[test log message einsteindb 3, foo]"}, 548 {"2020/08/26 06:21:16.011", "fidel", "trace", "[test log message fidel 4, foo]"}, 549 {"2020/08/26 06:22:16.011", "einsteindb", "trace", "[test log message einsteindb 4, foo]"}, 550 {"2020/08/26 06:22:17.011", "fidel", "CRITICAL", "[test log message fidel 5, foo]"}, 551 {"2020/08/26 06:23:13.011", "fidel", "info", "[test log message fidel 10, bar]"}, 552 {"2020/08/26 06:23:17.011", "einsteindb", "CRITICAL", "[test log message einsteindb 5, foo]"}, 553 {"2020/08/26 06:24:14.011", "fidel", "debug", "[test log message fidel 11, bar]"}, 554 {"2020/08/26 06:24:15.011", "einsteindb", "info", "[test log message einsteindb 10, bar]"}, 555 {"2020/08/26 06:25:13.011", "milevadb", "info", "[test log message milevadb 10, bar]"}, 556 {"2020/08/26 06:25:14.011", "milevadb", "debug", "[test log message milevadb 11, bar]"}, 557 {"2020/08/26 06:25:15.011", "fidel", "ERROR", "[test log message fidel 12, bar]"}, 558 {"2020/08/26 06:25:15.011", "milevadb", "ERROR", "[test log message milevadb 12, bar]"}, 559 {"2020/08/26 06:25:16.011", "milevadb", "TRACE", "[test log message milevadb 13, bar]"}, 560 {"2020/08/26 06:25:16.011", "einsteindb", "debug", "[test log message einsteindb 11, bar]"}, 561 {"2020/08/26 06:25:17.011", "milevadb", "critical", "[test log message milevadb 14, bar]"}, 562 {"2020/08/26 06:26:16.011", "fidel", "TRACE", "[test log message fidel 13, bar]"}, 563 {"2020/08/26 06:26:17.011", "einsteindb", "ERROR", "[test log message einsteindb 12, bar]"}, 564 {"2020/08/26 06:27:17.011", "fidel", "critical", "[test log message fidel 14, bar]"}, 565 {"2020/08/26 06:27:18.011", "einsteindb", "TRACE", "[test log message einsteindb 13, bar]"}, 566 {"2020/08/26 06:28:19.011", "einsteindb", "critical", "[test log message einsteindb 14, bar]"}, 567 } 568 569 var cases = []struct { 570 conditions []string 571 expected [][]string 572 }{ 573 { 574 conditions: []string{ 575 "time>='2020/08/26 06:18:13.011'", 576 "time<='2099/08/26 06:28:19.011'", 577 "message like '%'", 578 }, 579 expected: fullLogs, 580 }, 581 { 582 conditions: []string{ 583 "time>='2020/08/26 06:19:13.011'", 584 "time<='2020/08/26 06:21:15.011'", 585 "message like '%'", 586 }, 587 expected: [][]string{ 588 {"2020/08/26 06:19:13.011", "milevadb", "INFO", "[test log message milevadb 1, foo]"}, 589 {"2020/08/26 06:19:13.011", "einsteindb", "INFO", "[test log message einsteindb 1, foo]"}, 590 {"2020/08/26 06:19:14.011", "fidel", "DEBUG", "[test log message fidel 2, foo]"}, 591 {"2020/08/26 06:19:14.011", "milevadb", "DEBUG", "[test log message milevadb 2, foo]"}, 592 {"2020/08/26 06:19:15.011", "milevadb", "error", "[test log message milevadb 3, foo]"}, 593 {"2020/08/26 06:19:16.011", "milevadb", "trace", "[test log message milevadb 4, foo]"}, 594 {"2020/08/26 06:19:17.011", "milevadb", "CRITICAL", "[test log message milevadb 5, foo]"}, 595 {"2020/08/26 06:20:14.011", "einsteindb", "DEBUG", "[test log message einsteindb 2, foo]"}, 596 {"2020/08/26 06:20:15.011", "fidel", "error", "[test log message fidel 3, foo]"}, 597 {"2020/08/26 06:21:15.011", "einsteindb", "error", "[test log message einsteindb 3, foo]"}, 598 }, 599 }, 600 { 601 conditions: []string{ 602 "time>='2020/08/26 06:19:13.011'", 603 "time<='2020/08/26 06:21:15.011'", 604 "message like '%'", 605 "type='fidel'", 606 }, 607 expected: [][]string{ 608 {"2020/08/26 06:19:14.011", "fidel", "DEBUG", "[test log message fidel 2, foo]"}, 609 {"2020/08/26 06:20:15.011", "fidel", "error", "[test log message fidel 3, foo]"}, 610 }, 611 }, 612 { 613 conditions: []string{ 614 "time>='2020/08/26 06:18:13.011'", 615 "time>='2020/08/26 06:19:13.011'", 616 "time>='2020/08/26 06:19:14.011'", 617 "time<='2020/08/26 06:21:15.011'", 618 "type='fidel'", 619 }, 620 expected: [][]string{ 621 {"2020/08/26 06:19:14.011", "fidel", "DEBUG", "[test log message fidel 2, foo]"}, 622 {"2020/08/26 06:20:15.011", "fidel", "error", "[test log message fidel 3, foo]"}, 623 }, 624 }, 625 { 626 conditions: []string{ 627 "time>='2020/08/26 06:18:13.011'", 628 "time>='2020/08/26 06:19:13.011'", 629 "time='2020/08/26 06:19:14.011'", 630 "message like '%'", 631 "type='fidel'", 632 }, 633 expected: [][]string{ 634 {"2020/08/26 06:19:14.011", "fidel", "DEBUG", "[test log message fidel 2, foo]"}, 635 }, 636 }, 637 { 638 conditions: []string{ 639 "time>='2020/08/26 06:19:13.011'", 640 "time<='2020/08/26 06:21:15.011'", 641 "message like '%'", 642 "type='milevadb'", 643 }, 644 expected: [][]string{ 645 {"2020/08/26 06:19:13.011", "milevadb", "INFO", "[test log message milevadb 1, foo]"}, 646 {"2020/08/26 06:19:14.011", "milevadb", "DEBUG", "[test log message milevadb 2, foo]"}, 647 {"2020/08/26 06:19:15.011", "milevadb", "error", "[test log message milevadb 3, foo]"}, 648 {"2020/08/26 06:19:16.011", "milevadb", "trace", "[test log message milevadb 4, foo]"}, 649 {"2020/08/26 06:19:17.011", "milevadb", "CRITICAL", "[test log message milevadb 5, foo]"}, 650 }, 651 }, 652 { 653 conditions: []string{ 654 "time>='2020/08/26 06:19:13.011'", 655 "time<='2020/08/26 06:21:15.011'", 656 "message like '%'", 657 "type='einsteindb'", 658 }, 659 expected: [][]string{ 660 {"2020/08/26 06:19:13.011", "einsteindb", "INFO", "[test log message einsteindb 1, foo]"}, 661 {"2020/08/26 06:20:14.011", "einsteindb", "DEBUG", "[test log message einsteindb 2, foo]"}, 662 {"2020/08/26 06:21:15.011", "einsteindb", "error", "[test log message einsteindb 3, foo]"}, 663 }, 664 }, 665 { 666 conditions: []string{ 667 "time>='2020/08/26 06:19:13.011'", 668 "time<='2020/08/26 06:21:15.011'", 669 "message like '%'", 670 fmt.Sprintf("instance='%s'", testServers["fidel"].address), 671 }, 672 expected: [][]string{ 673 {"2020/08/26 06:19:14.011", "fidel", "DEBUG", "[test log message fidel 2, foo]"}, 674 {"2020/08/26 06:20:15.011", "fidel", "error", "[test log message fidel 3, foo]"}, 675 }, 676 }, 677 { 678 conditions: []string{ 679 "time>='2020/08/26 06:19:13.011'", 680 "time<='2020/08/26 06:21:15.011'", 681 "message like '%'", 682 fmt.Sprintf("instance='%s'", testServers["milevadb"].address), 683 }, 684 expected: [][]string{ 685 {"2020/08/26 06:19:13.011", "milevadb", "INFO", "[test log message milevadb 1, foo]"}, 686 {"2020/08/26 06:19:14.011", "milevadb", "DEBUG", "[test log message milevadb 2, foo]"}, 687 {"2020/08/26 06:19:15.011", "milevadb", "error", "[test log message milevadb 3, foo]"}, 688 {"2020/08/26 06:19:16.011", "milevadb", "trace", "[test log message milevadb 4, foo]"}, 689 {"2020/08/26 06:19:17.011", "milevadb", "CRITICAL", "[test log message milevadb 5, foo]"}, 690 }, 691 }, 692 { 693 conditions: []string{ 694 "time>='2020/08/26 06:19:13.011'", 695 "time<='2020/08/26 06:21:15.011'", 696 "message like '%'", 697 fmt.Sprintf("instance='%s'", testServers["einsteindb"].address), 698 }, 699 expected: [][]string{ 700 {"2020/08/26 06:19:13.011", "einsteindb", "INFO", "[test log message einsteindb 1, foo]"}, 701 {"2020/08/26 06:20:14.011", "einsteindb", "DEBUG", "[test log message einsteindb 2, foo]"}, 702 {"2020/08/26 06:21:15.011", "einsteindb", "error", "[test log message einsteindb 3, foo]"}, 703 }, 704 }, 705 { 706 conditions: []string{ 707 "time>='2020/08/26 06:19:13.011'", 708 "time<='2020/08/26 06:21:15.011'", 709 "message like '%'", 710 fmt.Sprintf("instance in ('%s', '%s')", testServers["fidel"].address, testServers["milevadb"].address), 711 }, 712 expected: [][]string{ 713 {"2020/08/26 06:19:13.011", "milevadb", "INFO", "[test log message milevadb 1, foo]"}, 714 {"2020/08/26 06:19:14.011", "fidel", "DEBUG", "[test log message fidel 2, foo]"}, 715 {"2020/08/26 06:19:14.011", "milevadb", "DEBUG", "[test log message milevadb 2, foo]"}, 716 {"2020/08/26 06:19:15.011", "milevadb", "error", "[test log message milevadb 3, foo]"}, 717 {"2020/08/26 06:19:16.011", "milevadb", "trace", "[test log message milevadb 4, foo]"}, 718 {"2020/08/26 06:19:17.011", "milevadb", "CRITICAL", "[test log message milevadb 5, foo]"}, 719 {"2020/08/26 06:20:15.011", "fidel", "error", "[test log message fidel 3, foo]"}, 720 }, 721 }, 722 { 723 conditions: []string{ 724 "time>='2020/08/26 06:18:13.011'", 725 "time<='2020/08/26 06:28:19.011'", 726 "message like '%'", 727 "level='critical'", 728 }, 729 expected: [][]string{ 730 {"2020/08/26 06:19:17.011", "milevadb", "CRITICAL", "[test log message milevadb 5, foo]"}, 731 {"2020/08/26 06:22:17.011", "fidel", "CRITICAL", "[test log message fidel 5, foo]"}, 732 {"2020/08/26 06:23:17.011", "einsteindb", "CRITICAL", "[test log message einsteindb 5, foo]"}, 733 {"2020/08/26 06:25:17.011", "milevadb", "critical", "[test log message milevadb 14, bar]"}, 734 {"2020/08/26 06:27:17.011", "fidel", "critical", "[test log message fidel 14, bar]"}, 735 {"2020/08/26 06:28:19.011", "einsteindb", "critical", "[test log message einsteindb 14, bar]"}, 736 }, 737 }, 738 { 739 conditions: []string{ 740 "time>='2020/08/26 06:18:13.011'", 741 "time<='2020/08/26 06:28:19.011'", 742 "message like '%'", 743 "level='critical'", 744 "type in ('fidel', 'einsteindb')", 745 }, 746 expected: [][]string{ 747 {"2020/08/26 06:22:17.011", "fidel", "CRITICAL", "[test log message fidel 5, foo]"}, 748 {"2020/08/26 06:23:17.011", "einsteindb", "CRITICAL", "[test log message einsteindb 5, foo]"}, 749 {"2020/08/26 06:27:17.011", "fidel", "critical", "[test log message fidel 14, bar]"}, 750 {"2020/08/26 06:28:19.011", "einsteindb", "critical", "[test log message einsteindb 14, bar]"}, 751 }, 752 }, 753 { 754 conditions: []string{ 755 "time>='2020/08/26 06:18:13.011'", 756 "time<='2020/08/26 06:28:19.011'", 757 "message like '%'", 758 "level='critical'", 759 "(type='fidel' or type='einsteindb')", 760 }, 761 expected: [][]string{ 762 {"2020/08/26 06:22:17.011", "fidel", "CRITICAL", "[test log message fidel 5, foo]"}, 763 {"2020/08/26 06:23:17.011", "einsteindb", "CRITICAL", "[test log message einsteindb 5, foo]"}, 764 {"2020/08/26 06:27:17.011", "fidel", "critical", "[test log message fidel 14, bar]"}, 765 {"2020/08/26 06:28:19.011", "einsteindb", "critical", "[test log message einsteindb 14, bar]"}, 766 }, 767 }, 768 { 769 conditions: []string{ 770 "time>='2020/08/26 06:18:13.011'", 771 "time<='2020/08/26 06:28:19.011'", 772 "level='critical'", 773 "message like '%fidel%'", 774 }, 775 expected: [][]string{ 776 {"2020/08/26 06:22:17.011", "fidel", "CRITICAL", "[test log message fidel 5, foo]"}, 777 {"2020/08/26 06:27:17.011", "fidel", "critical", "[test log message fidel 14, bar]"}, 778 }, 779 }, 780 { 781 conditions: []string{ 782 "time>='2020/08/26 06:18:13.011'", 783 "time<='2020/08/26 06:28:19.011'", 784 "level='critical'", 785 "message like '%fidel%'", 786 "message like '%5%'", 787 }, 788 expected: [][]string{ 789 {"2020/08/26 06:22:17.011", "fidel", "CRITICAL", "[test log message fidel 5, foo]"}, 790 }, 791 }, 792 { 793 conditions: []string{ 794 "time>='2020/08/26 06:18:13.011'", 795 "time<='2020/08/26 06:28:19.011'", 796 "level='critical'", 797 "message like '%fidel%'", 798 "message like '%5%'", 799 "message like '%x%'", 800 }, 801 expected: [][]string{}, 802 }, 803 { 804 conditions: []string{ 805 "time>='2020/08/26 06:18:13.011'", 806 "time<='2020/08/26 06:28:19.011'", 807 "level='critical'", 808 "message regexp '.*fidel.*'", 809 }, 810 expected: [][]string{ 811 {"2020/08/26 06:22:17.011", "fidel", "CRITICAL", "[test log message fidel 5, foo]"}, 812 {"2020/08/26 06:27:17.011", "fidel", "critical", "[test log message fidel 14, bar]"}, 813 }, 814 }, 815 { 816 conditions: []string{ 817 "time>='2020/08/26 06:18:13.011'", 818 "time<='2020/08/26 06:28:19.011'", 819 "level='critical'", 820 "message regexp '.*fidel.*'", 821 "message regexp '.*foo]$'", 822 }, 823 expected: [][]string{ 824 {"2020/08/26 06:22:17.011", "fidel", "CRITICAL", "[test log message fidel 5, foo]"}, 825 }, 826 }, 827 { 828 conditions: []string{ 829 "time>='2020/08/26 06:18:13.011'", 830 "time<='2020/08/26 06:28:19.011'", 831 "level='critical'", 832 "message regexp '.*fidel.*'", 833 "message regexp '.*5.*'", 834 "message regexp '.*x.*'", 835 }, 836 expected: [][]string{}, 837 }, 838 { 839 conditions: []string{ 840 "time>='2020/08/26 06:18:13.011'", 841 "time<='2020/08/26 06:28:19.011'", 842 "level='critical'", 843 "(message regexp '.*fidel.*' or message regexp '.*milevadb.*')", 844 }, 845 expected: [][]string{ 846 {"2020/08/26 06:19:17.011", "milevadb", "CRITICAL", "[test log message milevadb 5, foo]"}, 847 {"2020/08/26 06:22:17.011", "fidel", "CRITICAL", "[test log message fidel 5, foo]"}, 848 {"2020/08/26 06:25:17.011", "milevadb", "critical", "[test log message milevadb 14, bar]"}, 849 {"2020/08/26 06:27:17.011", "fidel", "critical", "[test log message fidel 14, bar]"}, 850 }, 851 }, 852 { 853 conditions: []string{ 854 "time>='2020/08/26 06:18:13.011'", 855 "time<='2099/08/26 06:28:19.011'", 856 // this pattern verifies that there is no optimization breaking 857 // length of multiple wildcards, for example, %% may be 858 // converted to %, but %_ cannot be converted to %. 859 "message like '%milevadb_%_4%'", 860 }, 861 expected: [][]string{ 862 {"2020/08/26 06:25:17.011", "milevadb", "critical", "[test log message milevadb 14, bar]"}, 863 }, 864 }, 865 } 866 867 var servers []string 868 for _, s := range testServers { 869 servers = append(servers, strings.Join([]string{s.typ, s.address, s.address}, ",")) 870 } 871 fpName := "github.com/whtcorpsinc/milevadb/interlock/mockClusterLogServerInfo" 872 fpExpr := strings.Join(servers, ";") 873 c.Assert(failpoint.Enable(fpName, fmt.Sprintf(`return("%s")`, fpExpr)), IsNil) 874 defer func() { c.Assert(failpoint.Disable(fpName), IsNil) }() 875 876 tk := testkit.NewTestKit(c, s.causetstore) 877 for _, cas := range cases { 878 allegrosql := "select * from information_schema.cluster_log" 879 if len(cas.conditions) > 0 { 880 allegrosql = fmt.Sprintf("%s where %s", allegrosql, strings.Join(cas.conditions, " and ")) 881 } 882 result := tk.MustQuery(allegrosql) 883 warnings := tk.Se.GetStochastikVars().StmtCtx.GetWarnings() 884 c.Assert(len(warnings), Equals, 0, Commentf("unexpected warnigns: %+v", warnings)) 885 var expected []string 886 for _, event := range cas.expected { 887 expectedEvent := []string{ 888 restime(event[0]), // time defCausumn 889 event[1], // type defCausumn 890 testServers[event[1]].address, // instance defCausumn 891 strings.ToUpper(sysutil.ParseLogLevel(event[2]).String()), // level defCausumn 892 event[3], // message defCausumn 893 } 894 expected = append(expected, strings.Join(expectedEvent, " ")) 895 } 896 result.Check(testkit.Events(expected...)) 897 } 898 } 899 900 func (s *testMemBlockReaderSuite) TestMilevaDBClusterLogError(c *C) { 901 tk := testkit.NewTestKit(c, s.causetstore) 902 fpName := "github.com/whtcorpsinc/milevadb/interlock/mockClusterLogServerInfo" 903 c.Assert(failpoint.Enable(fpName, `return("")`), IsNil) 904 defer func() { c.Assert(failpoint.Disable(fpName), IsNil) }() 905 906 // Test without start time error. 907 rs, err := tk.InterDirc("select * from information_schema.cluster_log") 908 c.Assert(err, IsNil) 909 _, err = stochastik.ResultSetToStringSlice(context.Background(), tk.Se, rs) 910 c.Assert(err, NotNil) 911 c.Assert(err.Error(), Equals, "denied to scan logs, please specified the start time, such as `time > '2020-01-01 00:00:00'`") 912 913 // Test without end time error. 914 rs, err = tk.InterDirc("select * from information_schema.cluster_log where time>='2020/08/26 06:18:13.011'") 915 c.Assert(err, IsNil) 916 _, err = stochastik.ResultSetToStringSlice(context.Background(), tk.Se, rs) 917 c.Assert(err, NotNil) 918 c.Assert(err.Error(), Equals, "denied to scan logs, please specified the end time, such as `time < '2020-01-01 00:00:00'`") 919 920 // Test without specified message error. 921 rs, err = tk.InterDirc("select * from information_schema.cluster_log where time>='2020/08/26 06:18:13.011' and time<'2020/08/26 16:18:13.011'") 922 c.Assert(err, IsNil) 923 _, err = stochastik.ResultSetToStringSlice(context.Background(), tk.Se, rs) 924 c.Assert(err, NotNil) 925 c.Assert(err.Error(), Equals, "denied to scan full logs (use `SELECT * FROM cluster_log WHERE message LIKE '%'` explicitly if intentionally)") 926 }