第17章　了解应用的动态

启动并运行应用后，要如何知道它正在做些什么呢？本章将介绍如何了解MongoDB正在进行何种查询，有多少数据正在写入，以及如何探查MongoDB具体正在做些什么。我们将学到：

  • 如何找到并终止那些拖慢速度的操作；
  • 获取并分析有关集合和数据库的统计数据；
  • 用命令行工具来了解MongoDB正在做些什么。

17.1　了解正在进行的操作

要想找到是哪些操作拖慢了速度，看看正在进行的操作不失为一种简单的方法。速度慢的操作耗时更长，更有可能被发现。虽然不能保证一定会有结果，但这是个不错的开始。

查看正在进行的操作，可使用db.currentOp()函数：

  1. > db.currentOp()
  2. {
  3.     "inprog" : [
  4.         {
  5.             "opid" : 34820,
  6.             "active" : true,
  7.             "secs_running" : 0,
  8.             "op" : "query",
  9.             "ns" : "test.users",
  10.             "query" : {
  11.                     "count" : "users",
  12.                     "query" : {
  13.                             "username" : "user12345"
  14.                      },
  15.                      "fields" : {
  17.                      }
  18.             },
  19.             "client" : "127.0.0.1:39931",
  20.             "desc" : "conn3",
  21.             "threadId" : "0x7f12d61c7700",
  22.             "connectionId" : 3,
  23.             "locks" : {
  24.                    "^" : "r",
  25.                    "^test" : "R"
  26.              },
  27.              "waitingForLock" : false,
  28.              "numYields" : 0,
  29.              "lockStats" : {
  30.                     "timeLockedMicros" : {
  32.                     },
  33.                     "timeAcquiringMicros" : {
  34.                             "r" : NumberLong(9),
  35.                             "w" : NumberLong(0)
  36.                              }
  37.                }
  38.          },
  39.          ...
  40.    ]
  41. }

该函数会列出数据库正在进行的所有操作，输出的信息中有些重要的字段。

  • opid

    这是操作的唯一标识符（identifier），可通过它来终止一个操作（参见17.1.2节）。

  • active

    表示该操作是否正在运行。如这一字段的值是false，意味着此操作已交出或正等待其他操作交出锁。

  • secs_running

    表示该操作已经执行的时间。可通过它来判断是哪些查询耗时过长，或者占用了过多的数据库资源。

  • op

    表示操作的类型。通常是查询、插入、更新、删除中的一种。注意，数据库命令也被作为查询操作来处理。

  • desc

    该值可与日志（log）信息联系起来。日志中与此连接相关的每一条记录都会以[conn3]为前缀，因此可以此来筛选相关的日志信息。

  • locks

    描述该操作使用的锁的类型。其中“^”表示全局锁。

  • waitingForLock

    表示该操作是否因正在等待其他操作交出锁而处于阻塞状态。

  • numYields

    表示该操作交出锁（yield），而使其他操作得以运行的次数。通常，进行文档搜索的操作（查询、更新和删除）可交出锁。只有在其他操作列队等待该操作所持的锁时，它才会交出自己的锁。简单地讲，如果没有其他操作处于waitingForLock状态，则该操作不会交出锁。

  • lockstats.timeAcquiringMicros

    表示该操作需要多长时间才能取得所需的锁。

在执行currentOp()时，可添加过滤条件，从而只显示符合条件的结果。例如，只显示在某一命名空间中进行的操作，或只显示已运行了一定时间的操作。把查询条件作为参数传入函数来进行过滤：

  1. > db.currentOp({"ns" : "prod.users"})

对于currentOp中的任何字段都可以进行查询，使用普通的查询语句即可。

17.1.1　寻找有问题的操作

db.currentOp()最常见的作用就是用来寻找速度较慢的操作。可采用上一节中提到的过滤方法，来查找哪些查询消耗的时间超过了一定的值。也许能通过该方法找出哪里缺少了索引，或是进行了不恰当的条件过滤。

有时会发现正在运行一些不明查询，这通常是由于一个应用服务器在运行一个旧的或有漏洞的软件版本所导致的。"client"字段可用来帮助追踪找出这些不明操作的来源。

17.1.2　终止操作的执行

只要找到了想要终止的操作，就可将该操作的opid作为参数，通过执行db.killOp()来终止该操作的执行：

  1. > db.killOp(123)

并非所有操作都能被终止。一般来讲，只有交出了锁的进程才能被终止，因此更新（update）、查找（find）、删除（remove）操作都可被终止。正在占用锁，或正在等待其他操作交出锁的操作则通常无法被终止。

如果向一个操作发出了“kill”信号，那么它在db.currentOp的输出中就会有一个killed字段。然而，只有从当前操作列表消失后，它才会真正的得到终止。

17.1.3　假象

在查找哪些操作耗时过长时，可能会发现一些长时间运行的内部操作。根据设置，MongoDB可能会长时间地执行若干请求。最常见的是用于复制（replication）的线程（它会持续向同步源请求更多的操作）和分片中用于回写（writeback）的监听器（listener）。所有local.oplog.rs中的长时间运行请求，以及所有回写监听命令，都可以被忽略掉。

如以上操作被终止，MongoDB则会重启它们。不过，通常我们不应该这么做。终止用于复制的线程会短暂地中止复制操作，而终止掉回写监听器则可能会造成mongos遗漏正常的写入错误。

17.1.4　避免幽灵操作

这是一个不常见的，只有在MongoDB中才可能会遇到的问题，尤其是在进行静态加载（bulk-loading）数据至集合的时候。假设现在我们建立了一个任务（job），用于在MongoDB中进行上千条更新操作，而MongoDB正逐渐趋于停止。我们迅速停止了这一任务，终止了正在进行的所有更新操作。然而，我们会发现新的更新操作不断出现，哪怕任务已经不再运行！

如果使用非应答式写入（unacknowledge write）加载数据，应用触发写入操作的速度可能要比MongoDB处理的速度更快。如MongoDB有所准备，这些写入会堆积在操作系统的套接字缓存（socket buffer）中。终止掉MongoDB正在进行的写入操作后，MongoDB则开始处理缓存区中的写入操作。即使停止客户端发送，MongoDB也会处理这些缓存中的写入请求，因为它们已经被MongoDB所接收了，只不过还没有进行处理而已。

阻止这些幽灵写入的最好方式是使用应答式写入，即每次写入操作都会等待上一次写入操作完成后才会进行下去，而非在上一次写入进入数据库服务器的缓存区就开始下一次写入。

17.2　使用系统分析器

可利用系统分析器（system profiler）来查找耗时过长的操作。系统分析器可记录特殊集合system.profile中的操作，并提供大量有关耗时过长的操作信息，但相应的，mongod的整体性能也会有所下降。因此，我们可能只需定期打开分析器来获取信息即可。如系统已经负载过重，则建议使用本章介绍的另一方法来解决问题。

默认情况下，系统分析器处于关闭状态，不会进行任何记录。可在shell中运行 db.setProfilingLevel()开启分析器：

  1. > db.setProfilingLevel(2)
  2. { "was" : 0, "slowms" : 100, "ok" : 1 }

以上命令将分析器的级别设定为2级，意味着“分析器会记录所有内容”。数据库收到的所有读写请求都将被记录在当前数据库的system.profile集合中。每一个数据库都启用了分析器，这也将带来大量的性能损失，因为每一次写操作都会增加额外的写入时间，而每一次读操作都要等待写锁（因为它必须在system.profile集合中写入记录）。然而，它也会提供给我们系统进行操作的详尽列表：

  1. > db.foo.insert({x:1})
  2. > db.foo.update({},{$set:{x:2}})
  3. > db.foo.remove()
  4. > db.system.profile.find().pretty()
  5. {
  6.         "ts" : ISODate("2012-11-07T18:32:35.219Z"),
  7.         "op" : "insert",
  8.         "ns" : "test.foo",
  9.         "millis" : 37,
  10.         "client" : "127.0.0.1",
  11.         "user" : ""
  12. }
  13. {
  14.         "ts" : ISODate("2012-11-07T18:32:47.334Z"),
  15.         "op" : "update",
  16.         "ns" : "test.foo",
  17.         "query" : {
  19.          },
  20.          "updateobj" : {
  21.                   "$set" : {
  22.                          "x" : 2
  23.                    }
  24.           },
  25.           "nscanned" : 1,
  26.           "fastmod" : true,
  27.            "millis" : 3,
  28.            "client" : "127.0.0.1",
  29.            "user" : ""
  30. }
  31. {
  32.            "ts" : ISODate("2012-11-07T18:32:50.058Z"),
  33.            "op" : "remove",
  34.            "ns" : "test.foo",
  35.            "query" : {
  36.             },
  37.             "millis" : 0,
  38.             "client" : "127.0.0.1",
  39.             "user" : ""
  40. }

在"client"（客户端）字段中可看到各操作是由哪个用户发送至数据库的。如果启用了身份验证系统，也能够看到各操作是由哪些用户运行的。

一般情况下， 我们只想关注那些耗时过长的操作，而非数据库中正在进行的所有操作。为此，可将分析器的分析级别设为1，即只显示长耗时操作。级别为1的分析器会默认记录耗时大于100 ms的操作。也可以自定义“耗时过长”的标准，把这个值作为db.setProfillingLevel()函数的第二个参数。以下命令会记录所有耗时超过500 ms的操作：

  1. > db.setProfilingLevel(1, 500)
  2. { "was" : 2, "slowms" : 100, "ok" : 1 }

将分析级别设为0可关闭分析器。

  1. > db.setProfilingLevel(0)
  2. { "was" : 1, "slowms" : 500, "ok" : 1 }

通常情况下，不要将slowms的值设得过小。即使分析器处于关闭状态，slowms也会对mongod有所影响，因为它决定了哪些操作将作为耗时过长操作被记录到日志中。因此，如果将slowms设为2 ms，那么哪怕分析器是关闭着的，每个耗时超过2 ms的操作也都会出现在日志里。因此，如果出于某些需求降低了slowms的值，那么应在关闭分析器前将它重新调高。

可通过db.getProfilingLevel()来查看当前的分析级别。分析级别的设定值会在重启数据库后被清除。

也可在命令行中使用--profile level和--slowms time选项来配置分析器的级别。但更改分析级别通常只是在调试时作为一种临时措施，而不应该将其长期地加入配置中。

如开启了分析器而system.profile集合并不存在，MongoDB会为其建立一个大小为若干MB的固定集合（capped collection）。如希望分析器运行更长时间，可能需要更大的空间来记录更多的操作。此时可关闭分析器，删除并重新建立一个新的名为system.profile的固定集合，并令其容量符合需求。然后在数据库上重新启用分析器。

17.3　计算空间消耗

如能得知文档、索引、集合、数据库各占用了多少空间，就可以方便地预留出合适的磁盘和内存空间。关于计算工作集大小的相关内容请参见第21章。

17.3.1　文档

要查询文档占用的空间大小，最简单的方法是在shell中对文档使用Object.bsonsize()函数。此函数将返回该文档存储在MongoDB中时占用的空间大小。

例如，我们可以看到，将_id存储为ObjectId类型，比存储为字符串类型效率更高。

  1. > Object.bsonsize({_id:ObjectId()})
  2. 22
  3. > // ""+ObjectId() 将 ObjectId 转换为字符串
  4. > Object.bsonsize({_id:""+ObjectId()})
  5. 39

也可以直接对集合中的文档进行查询：

  1. > Object.bsonsize(db.users.findOne())

这一函数会精确地告知文档在磁盘上占用的字节数目。然而这其中并未包括自动生成的空间间隔（padding）和索引，二者也时常是影响集合大小的重要因素。

17.3.2　集合

stats函数可用来显示一个集合的信息：

  1. > db.boards.stats()
  2. {
  3.        "ns" : "brains.boards",
  4.        "count" : 12,
  5.        "size" : 32292,
  6.        "avgObjSize" : 2691,
  7.        "storageSize" : 270336,
  8.        "numExtents" : 3,
  9.        "nindexes" : 2,
  10.        "lastExtentSize" : 212992,
  11.        "paddingFactor" : 1.0099999999999825,
  12.        "flags" : 1,
  13.        "totalIndexSize" : 16352,
  14.        "indexSizes" : {
  15.               "_id_" : 8176,
  16.               "username_1_slug_1" : 8176
  17.         },
  18.        "ok" : 1
  19. }

stats函数的返回结果中首先是命名空间（即brains.boards），接下来是集合中文档的数目。再接下来的几个字段与集合的大小有关。size的值相当于对此集合中的所有元素执行Object.bsonsize()，再将这些结果相加得到的值，即集合中所有文档占有的字节数。将avgObjSize（平均对象大小）和count相乘，也能得到size的值。

与之前提到的一样，所有文档占用的字节总数并不等于集合大小，集合还占用空间存放其他重要内容，即文档间的间隔和索引信息。而storageSize不仅包含这些内容，还包含集合两端预留的未经使用空间。集合末端总有些空余空间，以便新文档能够快速添加进来。

nindexes是集合中索引的数量。索引直到建立完成后才会被算在nindexes中，也只有在出现在此列表后才可以被使用。由于目前的集合还很小，所以每个索引都只有一个“桶”（bucket）大小（8 KB）。通常来讲，索引比存储的数据量大很多，含有很多空闲空间，以便在增加新入口（entry）时进行优化。使用右平衡索引（right-balanced index，参见5.1.1节）可将这一空闲空间减至最小。而随机分布的索引通常会有50%左右的空闲空间，升序索引（ascending-order index）则有10%的空闲空间。

随着集合的不断增长，stats()返回的巨大字节数目可能会变得不易辨识。因此，可在使用stats时传入比例因子（scale factor）：KB值为1024，MB则为1024×1024，依次类推。例如，以下命令会以TB为单位显示集合信息： 

  1. > db.big.stats(1024*1024*1024*1024)

17.3.3　数据库

数据库的stats函数与集合的类似：

  1. > db.stats()
  2. {
  3.          "db" : "brains",
  4.          "collections" : 11,
  5.          "objects" : 1109,
  6.          "avgObjSize" : 299.79440937781783,
  7.          "dataSize" : 332472,
  8.          "storageSize" : 1654784,
  9.          "numExtents" : 15,
  10.          "indexes" : 11,
  11.          "indexSize" : 114464,
  12.          "fileSize" : 201326592,
  13.          "nsSizeMB" : 16,
  14.          "ok" : 1
  15. }

首先返回的是数据库名称和其中包含的集合数目。objects的值是数据库中所有集合包含的文档总数。

输出中包含了有关数据大小的信息。fileSize应该总是最大的，即为数据库文件分配的总空间。该值应等于数据目录中所有名为brains.*的文件大小总和。

第二大的字段通常是storageSize，即数据库正在使用的总空间大小。该值与fileSize不符，因为fileSize包含了预分配（preallocated）文件。例如，如果数据目录中已经存在brains.0、brains.1和brains.2文件，则brains.2会被0填满。brains.2写入数据后，文件 brains.3会被预分配。每个数据库内应一直存在一个填充为0的空文件。该空文件被写入数据后，下一个文件则会被预分配。因此，该空文件（以及前面文件中未被使用的部分）造成了fileSize和storageSize间的差异。

dataSize是此数据库中的数据所占用的空间大小。注意，该值并不包含空闲列表（free list）中的空间，但包含了文档间的间隔。因此该值与storageSize值的差异，应为被删除文档的大小。。

与集合的stats()一样，db.stats()可接收一个比例因子作为参数。

如果对一个不存在的数据库使用db.stats()，则nsSizeMB的值为0。这是.ns文件的大小，它本质上相当于数据库中的内容表。任何存在的数据库均需一个.ns文件。

记住，在一个繁忙的系统上列出数据库信息会非常慢，而且会阻碍其他操作。因此应尽量避免此类操作。

17.4　使用mongotop和monogostat

MongoDB自带了几个命令行工具，可通过每隔几秒输出当前状态，帮助我们判断数据库正在做些什么。

mongotop类似于UNIX中的top工具，可概述哪个集合最为繁忙。可通过运行mongotop-locks，从而得知每个数据库的锁状态。

mongostat提供有关服务器的信息。mongostat默认每秒输出一次包含当前状态的列表，可在命令行中传入参数更改时间间隔。每个字段都会给出自上一次被输出以来，所对应的活动发生次数。

  • insert／query／update／delete／getmore／command

    每种对应操作的发生次数。

  • flushes

    mongod将数据刷新（flush）到磁盘的次数。

  • mapped

    mongod所映射的内存数量，通常约等于数据目录的大小。

  • vsize

    mongod正在使用的虚拟内存大小，通常为数据目录的2倍大小（一次用于映射的文件，一次用于日记系统）。

  • res

    mongod正在使用的内存大小，通常该值应尽量接近机器的所有内存大小。

  • locked db

    在上一个时间片中，锁定时间最长的数据库。该百分比是根据数据库被锁定的时间和全局锁的锁定时间来计算的，这意味着该值可能超过100%。

  • idx miss %

    输出中最令人困惑的字段名。指有多少索引在访问中发生了缺页中断（page fault），即索引入口（或被搜索的索引内容）不在内存中，使得mongod必须到磁盘中进行读取。

  • qr|qw

    读写操作的队列（queue）大小，即有多少读写操作被阻塞，等待进行处理。

  • ar|aw

    指活动客户端的数量，即正在进行读写操作的客户端。

  • netIn

    通过网络传输进来的字节数，由MongoDB进行统计（不必和操作系统的统计相等）。

  • netOut

    通过网络传输出的字节数，由MongoDB进行统计。

  • conn

    此服务器打开的连接数，包括输入和输出连接。

  • time

    指以上统计信息所用时间。

可在副本集或分片集群上运行mongostat。如使用--discover选项，mongostat会尝试在初始连接的成员中寻找副本集或分片集群中的所有成员，每台服务器也会每秒针对每个成员输出一行信息。对于较大集群而言，该选项会使数据输出过多过快而不易于管理，但于较小集群而言却很实用，也可使用一些工具将其输出的信息转换为更可读的形式。

要想获得数据库中正在进行的操作快照，mongostat是很好的选择，但如果要对数据库进行长期的监控，类似MMS的工具可能更为适合（参见第21章）。