【发布时间】:2021-07-03 00:57:12
【问题描述】:
我正在开发一个慢查询日志解析器包,它与 golang 中的慢查询日志回放器相关联。对于回放器,有以下代码(我在其中添加了 cmets 以提高可读性):
for {
// method from my package that returns a Query object, containing headers values
// and the query itself
q := p.GetNext()
if q == (query.Query{}) {
break
}
db.logger.Tracef("query: %s", q.Query)
// we send the SQL query to a chan that is read by workers.
// workers just execute the query on the database, that's all.
// results from the db query are handled in another piece of the code, it doesn't really
// matter here
queries <- q.Query
// We need a reference time
if firstPass {
firstPass = false
previousDate = q.Time
continue
}
// Time field contains the Time: field value in the query header
now := q.Time
sleeping := now.Sub(previousDate)
db.logger.Tracef("next sleeping time: %s", sleeping)
time.Sleep(sleeping) // Here is my issue. For MariaDB the value is < 0 so no sleep is done
// For MariaDB, when there is multiple queries in a short amount of
// time, the Time field is not repeated, so we do not have to update
// the previous date.
if now != (time.Time{}) {
previousDate = now
}
}
我遇到了一个有趣的问题:
在 MariaDB 慢查询日志中,如果 2 个(或更多)查询彼此接近,则头部没有 Time: 字段,这减少了前面代码 sn-p 中的time.Sleep(sleeping) 的数量。
但是,对于 MySQL 风格的慢查询日志,查询头中总是有一个 Time: 字段,这意味着对每个查询都进行睡眠(即使是 µs 睡眠时长)。
我注意到 MariaDB 和 MySQL 日志之间的重放时间差异很大; MariaDB 重播时间与实时非常相似(日志文件的第一次和最后一次查询之间的时间差),但另一方面 MySQL 重播时间比 IRL 高得多。在玩了pprof之后,我注意到问题来自time.Sleep,尤其是runtime.Futex,这很耗时。
我做了一些基准测试,持续时间结果与完成的time.Sleep 的数量相关(MySQL 高于 MariaDB)。
因此,我不是在单个线程中执行所有time.Sleep,而是在寻找一种不同的方法来并行执行它们而不改变有效时间,但我想不出办法来做到这一点。
【问题讨论】:
-
在我看来,您误读了 pprof 的输出。你还期待它展示什么?
-
time.sleep 调用的大量系统调用是一个已知问题:github.com/golang/go/issues/25471
-
你的目标是什么?以相同的速度执行相同的查询?或者测试一组查询可以运行多快?还是比较硬件配置?或者测试索引/等的变化?要么...? (坦率地说,我不明白您为什么要尝试模拟查询间延迟。)
-
这个想法是通过重放客户端查询来分析数据库的行为。这样,我可以将不同的云提供商性能(例如 Cloud SQL)与生产数据集进行比较,看看它是否比我当前的设置或其他云提供商更快/更慢。我编写的包将慢查询日志转换为查询对象,然后回放器在数据库上重放这些查询。对不起,如果我的解释不是很清楚!
标签: mysql performance go mariadb mysql-slow-query-log