SQLITE 查询性能差异太大而无法可靠或理解
Posted
技术标签:
【中文标题】SQLITE 查询性能差异太大而无法可靠或理解【英文标题】:SQLITE query performance differ too much to be reliable or understandable 【发布时间】:2011-07-19 12:12:25 【问题描述】:问题的简短版本。
有时,通常在一秒钟内运行的查询(使用索引)需要一分钟甚至更长时间才能执行。 EXPLAIN 表明没有对表进行全面扫描。数据库很大(2 Gb,450 万条记录)并且专门使用。再次重新运行相同的查询很快。直到某个特别的时刻……
问题的长版本。
我在 SQLITE 上有一个日志数据库:
CREATE TABLE log( id integer primary key autoincrement,
msg text,
created_at int,
kind text,
computer text,
process text,
who text
);
CREATE INDEX idxlog_created_at ON log(created_at);
CREATE INDEX idxlog_kind_computer_id ON log(kind,computer,id);
CREATE INDEX idxlog_kind_computer_process_id ON log(kind,computer,process,id);
CREATE INDEX idxlog_kind_computer_process_who_id ON log(kind,computer,process,who,id);
CREATE INDEX idxlog_kind_id ON log(kind,id);
kind ===> 'debug', 'error', 'warn', 'info' 计算机 ===> 计算机名称 进程 ===> 进程名称 who ===> 组件名称(将消息发送到日志) 创建索引以确保快速响应对日志的任何可能查询。 id 列包含在索引中以确保快速 ORDER BY。
Sqlite:3.7.7.1 平台:Windows XP 语言:Delphi 通过 sqlite3.dll(来自 sqlite.org) 编译指示(在此特定连接上):
PRAGMA encoding = "UTF-8";
PRAGMA foreign_keys = ON;
PRAGMA synchronous = NORMAL;
PRAGMA page_size = 8192;
PRAGMA automatic_index = 0;
PRAGMA temp_store = FILE;
打开 SQLITE 连接:
SQLite3_Open_v2(@UTF8String(AFileName)[1], Fdb,
SQLITE_OPEN_READWRITE or
SQLITE_OPEN_CREATE or
SQLITE_OPEN_PRIVATECACHE or
SQLITE_OPEN_NOMUTEX
);
日志查询示例:
SELECT
1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
FROM log
WHERE id > 4149245 AND id <= 9223372036854775807 AND kind = 'error'
UNION ALL
SELECT
1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
FROM log
WHERE id > 4149245 AND id <= 9223372036854775807 AND kind = 'debug'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
FROM log
WHERE id > 4149245 AND id <= 9223372036854775807 AND kind = 'timing'
ORDER BY id DESC LIMIT 100
每个查询都是按种类查询的 UNION,以确保使用索引。
数据库有约 450 万条记录,数据库文件大小约 1.8 Gb。数据库仅由日志记录进程使用(在这些测量期间没有进行额外的日志记录)。
现在,问题。
有时,此类查询的性能比“普通”性能慢 100 倍左右。
普通的表演不到一秒。现在,我已经对长时间运行的查询进行了计时并保存了信息。你在这里:
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
FROM log _computer_process_id
WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'error' AND computer='KRAFTWAY' AND process='D:\xxx.exe'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
FROM log _computer_process_id
WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'warn' AND computer='KRAFTWAY' AND process='D:\xxx.exe'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
FROM log _computer_process_id
WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'info' AND computer='KRAFTWAY' AND process='D:\xxx.exe'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
FROM log _computer_process_id
WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'debug' AND computer='KRAFTWAY' AND process='D:\xxx.exe'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
FROM log _computer_process_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'timing' AND computer='KRAFTWAY' AND process='D:\xxx.exe'
ORDER BY id DESC LIMIT 100
plan: 4,0,0,SEARCH TABLE log AS _computer_process_id USING INDEX idxlog_kind_computer_process_id (kind=? AND computer=? AND process=?) (~2 行) 5,0,0,SEARCH TABLE log AS _computer_process_id USING INDEX idxlog_kind_computer_process_id (kind=? AND computer=? AND process=?) (~2 rows) 3,0,0,复合子查询 4 和 5(联合所有) 6,0,0,SEARCH TABLE log AS _computer_process_id USING INDEX idxlog_kind_computer_process_id (kind=? AND computer=? AND process=?) (~2 rows) 2,0,0,复合子查询 3 和 6(联合所有) 7,0,0,SEARCH TABLE log AS _computer_process_id USING INDEX idxlog_kind_computer_process_id (kind=? AND computer=? AND process=?) (~2 rows) 1,0,0,复合子查询 2 和 7(联合所有) 8,0,0,SEARCH TABLE log AS _computer_process_id USING INDEX idxlog_kind_computer_process_id (kind=? AND computer=? AND process=?) (~2 rows) 0,0,0,复合子查询 1 和 8(联合所有)
61326 毫秒
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id FROM log _computer_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'error' AND computer='KRAFTWAY'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id FROM log _computer_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'warn' AND computer='KRAFTWAY'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id FROM log _computer_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'debug' AND computer='KRAFTWAY'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id FROM log _computer_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'timing' AND computer='KRAFTWAY' ORDER BY id DESC LIMIT 100
plan: 3,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id (kind=? AND computer=?) (~2 rows) 4,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id (kind=? AND computer=?) (~2 rows) 2,0,0,复合子查询 3 和 4(联合所有) 5,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id (kind=? AND computer=?) (~2 rows) 1,0,0,复合子查询 2 和 5(联合所有) 6,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id (kind=? AND computer=?) (~2 rows) 0,0,0,复合子查询 1 和 6(联合所有)
45643 毫秒
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id FROM log _computer_process_who_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'error' AND computer='KRAFTWAY' AND process='D:\xxx.exe' AND who='main(TMessageRouter)'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id FROM log _computer_process_who_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'warn' AND computer='KRAFTWAY' AND process='D:\xxx.exe' AND who='main(TMessageRouter)'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id FROM log _computer_process_who_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'info' AND computer='KRAFTWAY' AND process='D:\xxx.exe' AND who='main(TMessageRouter)'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id FROM log _computer_process_who_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'debug' AND computer='KRAFTWAY' AND process='D:\xxx.exe' AND who='main(TMessageRouter)'
UNION ALL
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id FROM log _computer_process_who_id WHERE id > 4149246 AND id <= 9223372036854775807 AND kind = 'timing' AND computer='KRAFTWAY' AND process='D:\xxx.exe' AND who='main(TMessageRouter)'
ORDER BY id DESC LIMIT 100
plan: 4,0,0,SEARCH TABLE log AS _computer_process_who_id USING INDEX idxlog_kind_computer_process_who_id (kind=? AND computer=? AND process=? AND who=?) (~2 行) 5,0,0,SEARCH TABLE log AS _computer_process_who_id USING INDEX idxlog_kind_computer_process_who_id (kind=? AND computer=? AND process=? AND who=?) (~2 rows) 3,0,0,复合子查询 4 和 5(联合所有) 6,0,0,SEARCH TABLE log AS _computer_process_who_id USING INDEX idxlog_kind_computer_process_who_id (kind=? AND computer=? AND process=? AND who=?) (~2 rows) 2,0,0,复合子查询 3 和 6(联合所有) 7,0,0,SEARCH TABLE log AS _computer_process_who_id USING INDEX idxlog_kind_computer_process_who_id (kind=? AND computer=? AND process=? AND who=?) (~2 rows) 1,0,0,复合子查询 2 和 7(联合所有) 8,0,0,SEARCH TABLE log AS _computer_process_who_id USING INDEX idxlog_kind_computer_process_who_id (kind=? AND computer=? AND process=? AND who=?) (~2 rows) 0,0,0,复合子查询 1 和 8(联合所有)
175899 毫秒
是的,这个查询正在执行 3 分钟。
查看每次查询后的计划?没错,在每个运行时间过长的查询之后,我都执行了“EXPLAIN QUERY PLAN”+ 查询 SQL 并保存了结果。可以清楚地看到计划中没有 SCAN。这意味着没有进行 FULL TABLE 扫描,使用索引并且一切正常。
是的,除了查询的时间,一切都很好。
在这样一个长时间运行的查询期间监控日志记录过程显示,磁盘 i/o 以大约每秒 1 Mb 的速率持续(这显然不是瓶颈,HDD 每秒可以达到 100 Mb)和大约为零的 CPU 活动。如果在调试器下暂停,长时间运行的线程在 sqlite.dll 的深处,以 ntdll.ZwReadFile 结尾。
我已经尝试并整理了所有内容。它运行得更快,但问题仍然存在。
如果我重新运行相同的查询,它几乎会立即执行。
相同的数据库,相同的查询。第一次运行 - 160 秒,第二次运行 - 2 秒。
另一个有趣的事实:运行时间最长的查询通常不返回任何行。
是的,我了解缓存和操作系统正在内存中保留一些页面。
我没关系。我不明白如果 SQLITE 需要页面,为什么它的阅读速度如此之慢?为什么以每秒 1 mb 的速度阅读? SQLITE 数据库中的数据是否过于分散,所以需要大量查找?那么为什么?使用索引来确保这不是问题,不是吗?
我完全一无所知,感谢任何帮助。
更新。
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id 来自日志 WHERE id > 4033214 AND id
联合所有
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id 来自日志 WHERE id > 4033214 AND id
联合所有
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id 来自日志 WHERE id > 4033214 AND id
联合所有
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id 来自日志 WHERE id > 4033214 AND id
联合所有
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id 从日志 WHERE id > 4033214 AND id
ORDER BY id DESC LIMIT 100
plan: 4,0,0,SEARCH TABLE log USING COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at (kind=? AND computer=? AND process=?) (~2 rows) 5,0,0,SEARCH TABLE log USING COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at (kind=? AND computer=? AND process=?) (~2 rows) 3,0,0,复合子查询 4 和 5(联合所有) 6,0,0,SEARCH TABLE log USING COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at (kind=? AND computer=? AND process=?) (~2 rows) 2,0,0,复合子查询 3 和 6(联合所有) 7,0,0,SEARCH TABLE log USING COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at (kind=? AND computer=? AND process=?) (~2 rows) 1,0,0,复合子查询 2 和 7(联合所有) 8,0,0,SEARCH TABLE log USING COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at (kind=? AND computer=? AND process=?) (~2 rows) 0,0,0,复合子查询 1 和 8(联合所有)
1138669 毫秒大约需要 18 分钟。
重新运行查询:小于 100 毫秒。
在这 18 分钟内,db 进程的读取速度约为每秒 500 Kb。
【问题讨论】:
只是好奇:这两个索引不够吗?CREATE INDEX idxlog_created_at ON log(created_at); CREATE INDEX idxlog_id_kind_computer_process_who ON log( id,kind,computer,process,who);
我需要按 id DESC 订购。如果 id 不包含在索引中,那么按 id 排序会很慢,不是吗?
id
被索引,它是第一个字段。通过删除其他索引,数据库会小得多。你可以测试一下。
我在 android 平台上的一个小型 SQLite 数据库中似乎也遇到了同样的问题
【参考方案1】:
我假设你得到了同意
PRAGMA integrity_check
你真的在设置排他锁吗?
PRAGMA locking_mode = EXCLUSIVE
您能否在具有相同架构和查询且数据更少的较小数据库上重现该问题?
【讨论】:
【参考方案2】:你不能:
CREATE INDEX i_informations ON log (computer ASC, process ASC, id DESC);
SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
FROM log _computer_process_id
WHERE id BETWEEN 4149247 AND 9223372036854775807
AND kind IN ('info','debug','timing')
AND computer='KRAFTWAY'
AND process='D:\xxx.exe'
ORDER BY id DESC limit 100
【讨论】:
以上是关于SQLITE 查询性能差异太大而无法可靠或理解的主要内容,如果未能解决你的问题,请参考以下文章