MongoDB 索引过时
MongoDB index going stale
使用 mongo 服务器 v3.6.16.
我有一个 mongo 集合，其中包含大约 1800 万条记录。记录以每天大约 100k 的速度添加。我有一个查询经常在依赖于两个值的集合上运行 - user_id 和 server_time_stamp。我为这两个字段设置了复合索引。
索引经常变得陈旧 - 查询需要几分钟才能完成，导致服务器烧掉它可以获取的所有 CPU。一旦我重新生成索引，查询就会很快发生。但是一两天后，索引又过时了。 （编辑。索引现在失败得更快 - 在 30 分钟内。）我不知道为什么索引会过时 - 我可以寻找什么？
编辑
这是索引字段：
{
"uid" : 1,
"server_time_stamp" : -1
}
和索引选项：
{
"v" : 2,
"name" : "server_time_stamp_1_uid_1",
"ns" : "sefaria.user_history"
}
这似乎是一个 Heisenbug。当我使用 "explain" 时，它表现良好。这是长查询日志中的病态查询之一，耗时 445 秒：
sefaria.user_history command: find { find: "user_history", filter: { server_time_stamp: { $gt: 1577918252 }, uid: 80588 }, sort: { _id: 1 }, lsid: { id: UUID("4936fb55-8514-4442-b852-306686985126") }, $db: "sefaria", $readPreference: { mode: "primaryPreferred" } } planSummary: IXSCAN { _id: 1 } keysExamined:17286277 docsExamined:17286277 cursorExhausted:1 numYields:142780 nreturned:79 reslen:35375 locks:{ Global: { acquireCount: { r: 285562 } }, Database: { acquireCount: { r: 142781 } }, Collection: { acquireCount: { r: 142781 } } } protocol:op_msg 445101ms
这是 explain 的高性能查询的结果，就在重新生成索引之后：
{
"queryPlanner" : {
"plannerVersion" : NumberInt(1),
"namespace" : "sefaria.user_history",
"indexFilterSet" : false,
"parsedQuery" : {
"$and" : [
{
"uid" : {
"$eq" : 80588.0
}
},
{
"server_time_stamp" : {
"$gt" : 1577918252.0
}
}
]
},
"winningPlan" : {
"stage" : "FETCH",
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"uid" : NumberInt(1),
"server_time_stamp" : NumberInt(-1)
},
"indexName" : "server_time_stamp_1_uid_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
],
"server_time_stamp" : [
]
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : NumberInt(2),
"direction" : "forward",
"indexBounds" : {
"uid" : [
"[80588.0, 80588.0]"
],
"server_time_stamp" : [
"[inf.0, 1577918252.0)"
]
}
}
},
"rejectedPlans" : [
{
"stage" : "FETCH",
"filter" : {
"server_time_stamp" : {
"$gt" : 1577918252.0
}
},
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"uid" : NumberInt(1),
"book" : NumberInt(1),
"last_place" : NumberInt(1)
},
"indexName" : "uid_1_book_1_last_place_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
],
"book" : [
],
"last_place" : [
]
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : NumberInt(2),
"direction" : "forward",
"indexBounds" : {
"uid" : [
"[80588.0, 80588.0]"
],
"book" : [
"[MinKey, MaxKey]"
],
"last_place" : [
"[MinKey, MaxKey]"
]
}
}
},
{
"stage" : "FETCH",
"filter" : {
"server_time_stamp" : {
"$gt" : 1577918252.0
}
},
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"uid" : NumberInt(1)
},
"indexName" : "uid",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
]
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : NumberInt(2),
"direction" : "forward",
"indexBounds" : {
"uid" : [
"[80588.0, 80588.0]"
]
}
}
}
]
},
"executionStats" : {
"executionSuccess" : true,
"nReturned" : NumberInt(97),
"executionTimeMillis" : NumberInt(1),
"totalKeysExamined" : NumberInt(97),
"totalDocsExamined" : NumberInt(97),
"executionStages" : {
"stage" : "FETCH",
"nReturned" : NumberInt(97),
"executionTimeMillisEstimate" : NumberInt(0),
"works" : NumberInt(99),
"advanced" : NumberInt(97),
"needTime" : NumberInt(0),
"needYield" : NumberInt(0),
"saveState" : NumberInt(3),
"restoreState" : NumberInt(3),
"isEOF" : NumberInt(1),
"invalidates" : NumberInt(0),
"docsExamined" : NumberInt(97),
"alreadyHasObj" : NumberInt(0),
"inputStage" : {
"stage" : "IXSCAN",
"nReturned" : NumberInt(97),
"executionTimeMillisEstimate" : NumberInt(0),
"works" : NumberInt(98),
"advanced" : NumberInt(97),
"needTime" : NumberInt(0),
"needYield" : NumberInt(0),
"saveState" : NumberInt(3),
"restoreState" : NumberInt(3),
"isEOF" : NumberInt(1),
"invalidates" : NumberInt(0),
"keyPattern" : {
"uid" : NumberInt(1),
"server_time_stamp" : NumberInt(-1)
},
"indexName" : "server_time_stamp_1_uid_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
],
"server_time_stamp" : [
]
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : NumberInt(2),
"direction" : "forward",
"indexBounds" : {
"uid" : [
"[80588.0, 80588.0]"
],
"server_time_stamp" : [
"[inf.0, 1577918252.0)"
]
},
"keysExamined" : NumberInt(97),
"seeks" : NumberInt(1),
"dupsTested" : NumberInt(0),
"dupsDropped" : NumberInt(0),
"seenInvalidated" : NumberInt(0)
}
}
},
"serverInfo" : {
"host" : "mongo-deployment-5cf4f4fff6-dz84r",
"port" : NumberInt(27017),
"version" : "3.6.15",
"gitVersion" : "18934fb5c814e87895c5e38ae1515dd6cb4c00f7"
},
"ok" : 1.0
}
sefaria.user_history command: find { find: "user_history", filter: { server_time_stamp: { $gt: 1577918252 }, uid: 80588 }, sort: { _id: 1 }, lsid: { id: UUID("4936fb55-8514-4442-b852-306686985126") }, $db: "sefaria", $readPreference: { mode: "primaryPreferred" } } planSummary: IXSCAN { _id: 1 } keysExamined:17286277 docsExamined:17286277 cursorExhausted:1 numYields:142780 nreturned:79 reslen:35375 locks:{ Global: { acquireCount: { r: 285562 } }, Database: { acquireCount: { r: 142781 } }, Collection: { acquireCount: { r: 142781 } } } protocol:op_msg 445101ms
查看查询计划，查询使用了_id索引。是不是因为你有一种 _id 字段。我看了你附上的其他计划。
"executionSuccess" : true,
"nReturned" : NumberInt(97),
"executionTimeMillis" : NumberInt(1),
"totalKeysExamined" : NumberInt(97),
"totalDocsExamined" : NumberInt(97),
返回/检查的文件数量是1:1的比例。
查询也正在使用
"indexName" : "server_time_stamp_1_uid_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
],
"server_time_stamp" : [
]
},
我认为这两个查询中都缺少某些内容。可能是好的计划中没有提到的那种。你能检查一下吗？
我认为这里的问题是内存。该实例在接近物理内存限制的情况下运行。我不能肯定地说，但我相信相关索引已从内存中删除，查询性能不佳是其结果。重新生成索引迫使它回到内存中（假设，其他东西被踢出了内存。）
我已经将实例放在内存更多的节点上，到目前为止它似乎表现良好。
此行为是由于索引无法选择性和 服务于排序。
慢速操作的日志行显示使用 _id 索引的操作。查询规划器可能做出此选择以避免必须在内存中对结果进行排序（注意缺少 hasSortStage: 1）。然而，因此，它需要扫描内存中更多的文档 (docsExamined:17286277)，这使得它需要更长的时间。
内存争用可能也起了一定作用。根据负载，内存中排序结果的开销可能导致将索引推出 RAM 并选择 _id 索引。
几点评论：
As Babu ，上面贴的解释不包括排序。包括排序可能会显示该阶段比 IXSCAN 消耗更多时间。
索引的名称 (server_time_stamp_1_uid_1) 建议将 server_time_stamp 放在索引的第一位，然后是 uid。应优先考虑平等匹配；即 uid 应该是 placed before ranges.
需要考虑的一些选项：
创建索引{ "uid" : 1, "_id" : 1, "server_time_stamp" : 1 }。有关使用索引进行排序的指导，请参阅 here。尽管考虑到 _id 和 server_time_stamp 都可能具有高基数，但结果可能是混合的，这意味着您可能仍在扫描文档以避免排序。
假设 _id 值是自动生成的，请考虑按 server_time_stamp 而不是 _id 排序。这将允许您使用 server_time_stamp_1_uid_1 进行绑定和排序。 server_time_stamp是一个时间戳，所以也会比较独特。
问题是关于运行良好并使用索引的查询突然停止使用索引并导致性能非常差。这分别记录在 查询计划 和 日志 中。
解释的输出：
查询计划的 "executionStats" 表示 "totalKeysExamined" : NumberInt(97)。查询过滤器使用在集合上定义的索引 ("stage" : "IXSCAN") 并使用复合索引 "server_time_stamp_1_uid_1"。此外，查询的排序使用索引（_id 上的索引）。因为它是查询，索引正在按预期工作。而且，"executionTimeMillis" : NumberInt(1) 表示这是一个高性能查询。
来自日志的详细信息：
{ ...
find: "user_history", filter: { server_time_stamp: { $gt: 1577918252 }, uid: 80588 }, sort: { _id: 1 }
planSummary: IXSCAN { _id: 1 } keysExamined:17286277 docsExamined:17286277 numYields:142780 nreturned:79
... }
从日志中，请注意索引 "server_time_stamp_1_uid_1" 未 使用。
讨论：
经常使用的查询的数据和索引（称为working set）保存在内存（RAM + 文件系统缓存）中。如果工作集不在内存中，系统必须在操作期间将其加载到内存中，这会导致性能下降。从磁盘驱动器读取比内存慢得多。请注意，SSD 驱动器比 HDD 驱动器快得多，当没有增加内存的选项时，这可能是一个选项。
此外，如果查询正在使用索引并且索引大小很大并且不能在内存中，则必须从磁盘驱动器读取索引，这会减慢操作速度。更多内存是一种解决方案，如果不可能，解决方案可以是重新设计（或重新建模）数据及其索引。
但是，这种情况下的问题不是可用内存；够了。
以下信息给出了关于给定查询的工作集可能使用多少内存的想法：
db.collection.stats().indexSizes、size、count 和 avgObjSize.
解决方案：
性能慢的查询日志显示未使用索引"server_time_stamp_1_uid_1"：planSummary: IXSCAN { _id: 1 }.
确保并强制查询（始终）使用索引的一种方法是在查询中使用 hint。 hint 需要在索引 "server_time_stamp_1_uid_1" 上。这样就不会出现日志中看到的情况了。
另一种方法是让索引在内存中保持活动状态。这可以通过 运行 仅对索引字段进行查询来实现（覆盖查询：查询过滤器和返回的字段仅包含索引字段）。 运行 这个 dummy 查询，在实际查询之前经常运行 or 将确保索引在内存中可用。
在这种情况下，正如@Laizer 提到的那样，向查询提供 hint 有助于解决问题。
使用 mongo 服务器 v3.6.16.
我有一个 mongo 集合，其中包含大约 1800 万条记录。记录以每天大约 100k 的速度添加。我有一个查询经常在依赖于两个值的集合上运行 - user_id 和 server_time_stamp。我为这两个字段设置了复合索引。
索引经常变得陈旧 - 查询需要几分钟才能完成，导致服务器烧掉它可以获取的所有 CPU。一旦我重新生成索引，查询就会很快发生。但是一两天后，索引又过时了。 （编辑。索引现在失败得更快 - 在 30 分钟内。）我不知道为什么索引会过时 - 我可以寻找什么？
编辑
这是索引字段：
{
"uid" : 1,
"server_time_stamp" : -1
}
和索引选项：
{
"v" : 2,
"name" : "server_time_stamp_1_uid_1",
"ns" : "sefaria.user_history"
}
这似乎是一个 Heisenbug。当我使用 "explain" 时，它表现良好。这是长查询日志中的病态查询之一，耗时 445 秒：
sefaria.user_history command: find { find: "user_history", filter: { server_time_stamp: { $gt: 1577918252 }, uid: 80588 }, sort: { _id: 1 }, lsid: { id: UUID("4936fb55-8514-4442-b852-306686985126") }, $db: "sefaria", $readPreference: { mode: "primaryPreferred" } } planSummary: IXSCAN { _id: 1 } keysExamined:17286277 docsExamined:17286277 cursorExhausted:1 numYields:142780 nreturned:79 reslen:35375 locks:{ Global: { acquireCount: { r: 285562 } }, Database: { acquireCount: { r: 142781 } }, Collection: { acquireCount: { r: 142781 } } } protocol:op_msg 445101ms
这是 explain 的高性能查询的结果，就在重新生成索引之后：
{
"queryPlanner" : {
"plannerVersion" : NumberInt(1),
"namespace" : "sefaria.user_history",
"indexFilterSet" : false,
"parsedQuery" : {
"$and" : [
{
"uid" : {
"$eq" : 80588.0
}
},
{
"server_time_stamp" : {
"$gt" : 1577918252.0
}
}
]
},
"winningPlan" : {
"stage" : "FETCH",
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"uid" : NumberInt(1),
"server_time_stamp" : NumberInt(-1)
},
"indexName" : "server_time_stamp_1_uid_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
],
"server_time_stamp" : [
]
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : NumberInt(2),
"direction" : "forward",
"indexBounds" : {
"uid" : [
"[80588.0, 80588.0]"
],
"server_time_stamp" : [
"[inf.0, 1577918252.0)"
]
}
}
},
"rejectedPlans" : [
{
"stage" : "FETCH",
"filter" : {
"server_time_stamp" : {
"$gt" : 1577918252.0
}
},
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"uid" : NumberInt(1),
"book" : NumberInt(1),
"last_place" : NumberInt(1)
},
"indexName" : "uid_1_book_1_last_place_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
],
"book" : [
],
"last_place" : [
]
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : NumberInt(2),
"direction" : "forward",
"indexBounds" : {
"uid" : [
"[80588.0, 80588.0]"
],
"book" : [
"[MinKey, MaxKey]"
],
"last_place" : [
"[MinKey, MaxKey]"
]
}
}
},
{
"stage" : "FETCH",
"filter" : {
"server_time_stamp" : {
"$gt" : 1577918252.0
}
},
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"uid" : NumberInt(1)
},
"indexName" : "uid",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
]
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : NumberInt(2),
"direction" : "forward",
"indexBounds" : {
"uid" : [
"[80588.0, 80588.0]"
]
}
}
}
]
},
"executionStats" : {
"executionSuccess" : true,
"nReturned" : NumberInt(97),
"executionTimeMillis" : NumberInt(1),
"totalKeysExamined" : NumberInt(97),
"totalDocsExamined" : NumberInt(97),
"executionStages" : {
"stage" : "FETCH",
"nReturned" : NumberInt(97),
"executionTimeMillisEstimate" : NumberInt(0),
"works" : NumberInt(99),
"advanced" : NumberInt(97),
"needTime" : NumberInt(0),
"needYield" : NumberInt(0),
"saveState" : NumberInt(3),
"restoreState" : NumberInt(3),
"isEOF" : NumberInt(1),
"invalidates" : NumberInt(0),
"docsExamined" : NumberInt(97),
"alreadyHasObj" : NumberInt(0),
"inputStage" : {
"stage" : "IXSCAN",
"nReturned" : NumberInt(97),
"executionTimeMillisEstimate" : NumberInt(0),
"works" : NumberInt(98),
"advanced" : NumberInt(97),
"needTime" : NumberInt(0),
"needYield" : NumberInt(0),
"saveState" : NumberInt(3),
"restoreState" : NumberInt(3),
"isEOF" : NumberInt(1),
"invalidates" : NumberInt(0),
"keyPattern" : {
"uid" : NumberInt(1),
"server_time_stamp" : NumberInt(-1)
},
"indexName" : "server_time_stamp_1_uid_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
],
"server_time_stamp" : [
]
},
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : NumberInt(2),
"direction" : "forward",
"indexBounds" : {
"uid" : [
"[80588.0, 80588.0]"
],
"server_time_stamp" : [
"[inf.0, 1577918252.0)"
]
},
"keysExamined" : NumberInt(97),
"seeks" : NumberInt(1),
"dupsTested" : NumberInt(0),
"dupsDropped" : NumberInt(0),
"seenInvalidated" : NumberInt(0)
}
}
},
"serverInfo" : {
"host" : "mongo-deployment-5cf4f4fff6-dz84r",
"port" : NumberInt(27017),
"version" : "3.6.15",
"gitVersion" : "18934fb5c814e87895c5e38ae1515dd6cb4c00f7"
},
"ok" : 1.0
}
sefaria.user_history command: find { find: "user_history", filter: { server_time_stamp: { $gt: 1577918252 }, uid: 80588 }, sort: { _id: 1 }, lsid: { id: UUID("4936fb55-8514-4442-b852-306686985126") }, $db: "sefaria", $readPreference: { mode: "primaryPreferred" } } planSummary: IXSCAN { _id: 1 } keysExamined:17286277 docsExamined:17286277 cursorExhausted:1 numYields:142780 nreturned:79 reslen:35375 locks:{ Global: { acquireCount: { r: 285562 } }, Database: { acquireCount: { r: 142781 } }, Collection: { acquireCount: { r: 142781 } } } protocol:op_msg 445101ms
查看查询计划，查询使用了_id索引。是不是因为你有一种 _id 字段。我看了你附上的其他计划。
"executionSuccess" : true,
"nReturned" : NumberInt(97),
"executionTimeMillis" : NumberInt(1),
"totalKeysExamined" : NumberInt(97),
"totalDocsExamined" : NumberInt(97),
返回/检查的文件数量是1:1的比例。
查询也正在使用
"indexName" : "server_time_stamp_1_uid_1",
"isMultiKey" : false,
"multiKeyPaths" : {
"uid" : [
],
"server_time_stamp" : [
]
},
我认为这两个查询中都缺少某些内容。可能是好的计划中没有提到的那种。你能检查一下吗？
我认为这里的问题是内存。该实例在接近物理内存限制的情况下运行。我不能肯定地说，但我相信相关索引已从内存中删除，查询性能不佳是其结果。重新生成索引迫使它回到内存中（假设，其他东西被踢出了内存。）
我已经将实例放在内存更多的节点上，到目前为止它似乎表现良好。
此行为是由于索引无法选择性和 服务于排序。
慢速操作的日志行显示使用 _id 索引的操作。查询规划器可能做出此选择以避免必须在内存中对结果进行排序（注意缺少 hasSortStage: 1）。然而，因此，它需要扫描内存中更多的文档 (docsExamined:17286277)，这使得它需要更长的时间。
内存争用可能也起了一定作用。根据负载，内存中排序结果的开销可能导致将索引推出 RAM 并选择 _id 索引。
几点评论：
As Babu
索引的名称 (
server_time_stamp_1_uid_1) 建议将server_time_stamp放在索引的第一位，然后是uid。应优先考虑平等匹配；即uid应该是 placed before ranges.
需要考虑的一些选项：
创建索引
{ "uid" : 1, "_id" : 1, "server_time_stamp" : 1 }。有关使用索引进行排序的指导，请参阅 here。尽管考虑到_id和server_time_stamp都可能具有高基数，但结果可能是混合的，这意味着您可能仍在扫描文档以避免排序。假设
_id值是自动生成的，请考虑按server_time_stamp而不是_id排序。这将允许您使用server_time_stamp_1_uid_1进行绑定和排序。server_time_stamp是一个时间戳，所以也会比较独特。
问题是关于运行良好并使用索引的查询突然停止使用索引并导致性能非常差。这分别记录在 查询计划 和 日志 中。
解释的输出：
查询计划的 "executionStats" 表示 "totalKeysExamined" : NumberInt(97)。查询过滤器使用在集合上定义的索引 ("stage" : "IXSCAN") 并使用复合索引 "server_time_stamp_1_uid_1"。此外，查询的排序使用索引（_id 上的索引）。因为它是查询，索引正在按预期工作。而且，"executionTimeMillis" : NumberInt(1) 表示这是一个高性能查询。
来自日志的详细信息：
{ ...
find: "user_history", filter: { server_time_stamp: { $gt: 1577918252 }, uid: 80588 }, sort: { _id: 1 }
planSummary: IXSCAN { _id: 1 } keysExamined:17286277 docsExamined:17286277 numYields:142780 nreturned:79
... }
从日志中，请注意索引 "server_time_stamp_1_uid_1" 未 使用。
讨论：
经常使用的查询的数据和索引（称为working set）保存在内存（RAM + 文件系统缓存）中。如果工作集不在内存中，系统必须在操作期间将其加载到内存中，这会导致性能下降。从磁盘驱动器读取比内存慢得多。请注意，SSD 驱动器比 HDD 驱动器快得多，当没有增加内存的选项时，这可能是一个选项。
此外，如果查询正在使用索引并且索引大小很大并且不能在内存中，则必须从磁盘驱动器读取索引，这会减慢操作速度。更多内存是一种解决方案，如果不可能，解决方案可以是重新设计（或重新建模）数据及其索引。
但是，这种情况下的问题不是可用内存；够了。
以下信息给出了关于给定查询的工作集可能使用多少内存的想法：
db.collection.stats().indexSizes、size、count 和 avgObjSize.
解决方案：
性能慢的查询日志显示未使用索引"server_time_stamp_1_uid_1"：planSummary: IXSCAN { _id: 1 }.
确保并强制查询（始终）使用索引的一种方法是在查询中使用 hint。 hint 需要在索引 "server_time_stamp_1_uid_1" 上。这样就不会出现日志中看到的情况了。
另一种方法是让索引在内存中保持活动状态。这可以通过 运行 仅对索引字段进行查询来实现（覆盖查询：查询过滤器和返回的字段仅包含索引字段）。 运行 这个 dummy 查询，在实际查询之前经常运行 or 将确保索引在内存中可用。
在这种情况下，正如@Laizer 提到的那样，向查询提供 hint 有助于解决问题。