Gre*_*ory 5 database sqlite performance windows-xp
短版的问题.
有时,通常在一秒钟内运行的查询(使用索引)需要一分钟甚至更长时间才能执行.EXPLAIN显示没有进行全表扫描.数据库很大(2 Gb,4.5百万条记录)并且是专门使用的.再次重新运行相同的查询很快.直到某个特殊时刻......
长版本的问题.
我在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'
计算机===>计算机名称
进程===>进程名称
===>组件名称(发送消息进行记录)
索引创建是为了确保快速响应对日志的任何可能查询.id列包含在索引中以确保快速ORDER BY.
Sqlite:3.7.7.1
平台:Windows XP
语言:Delphi通过sqlite3.dll(来自sqlite.org)
Pragma(在这个特定的连接上):
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
计划: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计算机=？AND进程=？)(~2行)3,0,0,复合子查询4和5(UNION ALL)6,0,0,SEARCH TABLE log AS _computer_process_id使用INDEX idxlog_kind_computer_process_id(kind =？AND computer =？AND process =？)(~2行)2,0,0,COMPOUND SUBQUERIES 3和6(UNION ALL)7,0,0,SEARCH TABLE log AS _computer_process_id USING INDEX idxlog_kind_computer_process_id(kind =？AND computer =？ AND process =？)(~2行)1,0,0,COMPOUND SUBQUERIES 2和7(UNION ALL)8,0,0,SEARCH TABLE log AS _computer_process_id USING INDEX idxlog_kind_computer_process_id(kind =？AND computer =？AND process = ？)(~2行)0,0,0,复合子项1和8(UNION ALL)
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
计划:3,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id(kind =？AND computer =？)(~2行)4,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id(kind =？AND computer) =？)(~2行)2,0,0,COMPOUND SUBQUERIES 3和4(UNION ALL)5,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id(kind =？AND computer =？)(~2行)1,0,0,复合子查询2和5(UNION ALL)6,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id(kind =？AND computer =？)(~2行)0,0,0,复合子项1和6(UNION ALL)
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
计划: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行)3,0,0,COMPOUND SUBQUERIES 4和5(UNION ALL)6,0,0,SEARCH TABLE log AS _computer_process_who_id使用INDEX idxlog_kind_computer_process_who_id(kind =？AND computer =？AND process =？AND who =？)(~2行)2,0,0,COMPOUND SUBQUERIES 3和6(UNION ALL)7,0,0,SEARCH TABLE log AS _computer_process_who_id使用INDEX idxlog_kind_computer_process_who_id(kind =？AND computer =？AND process =？AND who =？)(~2行)1,0,0,COMPOUND SUBQUERIES 2和7(UNION ALL)8,0,0,SEARCH TABLE log AS _computer_process_who_id使用INDEX idxlog_kind_computer_process_who_id(kind =？AND computer =？AND process =？AND who =？)(~2行)0,0,0,COMPOUND SUBQUERIES 1和8(UNION ALL)
175899毫秒
是的,这个查询执行了3分钟.
在每次查询后查看计划？这是正确的,在每次执行太长时间的查询后,我执行了"EXPLAIN QUERY PLAN"+ SQL查询并保存了结果.人们可以清楚地看到计划中没有扫描.这意味着不会进行FULL TABLE扫描,使用索引并且一切正常.
是的,除了查询的时候,一切都还可以.
在这样一个长时间运行的查询期间监视日志记录过程显示每秒大约1 Mb的固定磁盘I/O(这显然不是瓶颈,HDD可以达到每秒100 Mb)和大约零CPU活动.如果在调试器下暂停,长时间运行的线程在sqlite.dll深处,以ntdll.ZwReadFile结尾.
我试过并整理了一切.它运行得更快,但问题仍然存在.
如果我重新运行相同的查询,它几乎立即执行.
相同的数据库,相同的查询 首次运行 - 160秒,第二次运行 - 2秒.
另一个有趣的事实:运行时间最长的查询通常不返回任何行
是的,我理解缓存和操作系统将一些页面保留在内存中.
那对我来说没问题.我不明白为什么SQLITE如果需要页面那么读得那么慢？为什么以每秒1 mb的速率读取？数据是否在SQLITE数据库中分散得太多,所以有很多寻求？那么为什么？指数用于确保这不是问题,不是吗？
我完全无能为力,感谢任何帮助.
UPDATE.
SELECT 1 as today,id as rowid,kind,who,msg,computer,process,created_at,id FROM log WHERE id> 4033214 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 WHERE id> 4033214 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 WHERE id> 4033214 AND id <= 9223372036854775807 AND kind ='info'AND computer ='KRAFTWAY'AND process ='DD :\ xxx.exe"
UNION ALL
SELECT 1 as today,id as rowid,kind,who,msg,computer,process,created_at,id FROM log WHERE id> 4033214 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 WHERE id> 4033214 AND id <= 9223372036854775807 AND kind ='timing'AND computer ='KRAFTWAY'AND process ='D :\ xxx.exe"
ORDER BY id DESC LIMIT 100
计划:4,0,0,SEARCH TABLE日志使用COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at(kind =？AND computer =？AND process =？)(~2行)5,0,0,SEARCH TABLE log使用COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at(kind =？ AND computer =？AND process =？)(~2行)3,0,0,COMPOUND SUBQUERIES 4和5(UNION ALL)6,0,0,SEARCH TABLE log使用COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at(kind =？AND computer =？ AND process =？)(~2行)2,0,0,COMPOUND SUBQUERIES 3和6(UNION ALL)7,0,0,SEARCH TABLE log using COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at(kind =？AND computer =？AND process =？ )(~~ 2行)1,0,0,复合子查询2和7(UNION ALL)8,0,0,SEARCH TABLE log使用COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at(kind =？AND computer =？AND process =？)(~2行)0,0,0,复合子查询1和8(UNION ALL)
1138669 ms这是~18分钟.
重新运行查询:小于100毫秒.
在这18分钟内,db过程以大约500 Kb /秒的速率读取.
我假设你得到了 OK
PRAGMA integrity_check
你真的设置了独占锁定吗？
PRAGMA locking_mode = EXCLUSIVE
您能否在具有相同架构和查询但数据较少的较小数据库上重现该问题？