database - SQLITE 查询性能差异太大而无法可靠或可理解

Question

问题的简短版本。

有时， 通常在一秒钟内运行的查询(使用索引)需要一分钟甚至更长时间来执行 。 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);

种类 ===> '调试'、'错误'、'警告'、'信息'
计算机 ===> 计算机名称
进程 ===> 进程名称
谁 ===> 组件名称(发送消息到日志)
创建索引以确保快速响应对日志的任何可能查询。
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

计划: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 行)
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 行)
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 行)
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 行)
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

计划: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,复合子查询 3 和 4(联合所有)
5,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id (kind=? AND computer=?)(~2 行)
1,0,0,复合子查询 2 和 5(联合所有)
6,0,0,SEARCH TABLE log AS _computer_id USING INDEX idxlog_kind_computer_id (kind=? AND computer=?)(~2 行)
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

计划: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,复合子查询 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 行)
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 行)
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 行)
0,0,0,复合子查询 1 和 8(联合所有)

175899 毫秒

是的，这个查询正在执行 3 分钟 。

每次查询后查看计划？没错，在每次运行时间过长的查询之后，我都执行了“EXPLAIN QUERY PLAN”+ 查询的 SQL 并保存了结果。人们可以清楚地看到计划中没有 SCAN。这意味着没有进行全表扫描，使用索引并且一切正常。

是的，除了查询时间，一切都好。

在这样一个长时间运行的查询期间监控日志记录过程显示恒定的磁盘 i/o 以大约每秒 1 Mb 的速率(这显然不是瓶颈，HDD 可以做到每秒 100 Mb)和大约零 CPU 事件。如果在调试器下暂停，长时间运行的线程位于以 ntdll.ZwReadFile 结尾的 sqlite.dll 深处。

我已经尝试并整理了所有内容。它运行得更快，但问题仍然存在。

如果我重新运行相同的查询，它几乎立即执行。

相同的数据库，相同的查询。第一次运行 - 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 <= 9223372036854775807 AND kind = 'error' AND computer='KRAFTWAY' AND process='D:\xxx.exe'

联合所有

SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
从日志
WHERE id > 4033214 AND id <= 9223372036854775807 AND kind = 'warn' AND computer='KRAFTWAY' AND process='D:\xxx.exe'

联合所有

SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
从日志
WHERE id > 4033214 AND id <= 9223372036854775807 AND kind = 'info' AND computer='KRAFTWAY' AND process='DD:\xxx.exe'

联合所有

SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
从日志
WHERE id > 4033214 AND id <= 9223372036854775807 AND kind = 'debug' AND computer='KRAFTWAY' AND process='D:\xxx.exe'

联合所有

SELECT 1 as today, id as rowid, kind,who,msg,computer,process,created_at,id
从日志 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 log USING COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at (kind=? AND computer=? AND process=?)(~2 行)
5,0,0,SEARCH TABLE log USING COVERING INDEX idxlog_kind_computer_process_id_who_msg_created_at (kind=? AND computer=? AND process=?)(~2 行)
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 行)
2,0,0,复合子查询 3 和 6(联合所有)
7,0,0,SEARCH TABLE 日志使用覆盖索引 idxlog_kind_computer_process_id_who_msg_created_at (kind=? AND computer=? AND process=?)(~2 行)
1,0,0,复合子查询 2 和 7(联合所有)
8,0,0,SEARCH TABLE 日志使用覆盖索引 idxlog_kind_computer_process_id_who_msg_created_at (kind=? AND computer=? AND process=?)(~2 行)
0,0,0,复合子查询 1 和 8(联合所有)

1138669 毫秒 大约 18 分钟。

重新运行查询:小于 100 毫秒。

在这 18 分钟内，db 进程的读取速度约为每秒 500 Kb。

Answer 1

我假设你从

PRAGMA integrity_check

你真的在设置排他锁吗？

PRAGMA locking_mode = EXCLUSIVE

您能否在具有相同架构和查询的较小数据库上重现该问题，只是数据较少？