集群日志分析方法

用户在使用 SequoiaDB 巨杉数据库的过程中，如果遇到一些由数据库抛出的异常错误，可以通过 sdbdiag.log 日志来定位问题。在进行集群日志分析前，用户可以先参考 SequoiaDB 的数据库存储引擎，了解 SequoiaDB 中各类节点在请求执行中的作用。

diaglog 问题诊断

用户在使用 SequoiaDB 集群时，如果遇到命令执行失败，或者查询数据抛出异常，sdbdiag.log 日志能够帮助用户快速定位具体失败原因，并且及时解决。例如，当用户向数据库进行数据写入时，数据无法写入，写入操作执行失败。具体执行命令如下：

  1. > db.sample.employee.insert({"id": 1001, "name": "zhangSan"})
  2. sdb.js:625 uncaught exception: -105
  3. Not enough number of data nodes
  4. Takes 0.006951s.

SequoiaDB 处理请求时的执行过程是协调节点接收客户端的请求并转发给对应的数据节点，数据节点将执行结果返回协调节点并汇总返回客户端。用户在进行日志分析时首先分析协调节点日志，然后分析数据节点日志。以下是具体分析步骤：

1.分析协调节点的诊断日志，查看方式可参考节点诊断日志章节，找出异常的根源。通过分析示例日志，可以看到记录在插入 “GroupID:1000, NodeID:1001” 节点时失败：

  1. ...
  2. 2019-07-05-13.38.41.145166               Level:ERROR
  3. PID:7038                                 TID:7507
  4. Function:execute                         Line:341
  5. File:SequoiaDB/engine/coord/coordInsertOperator.cpp
  6. Message:
  7. Insert failed on node[{ GroupID:1000, NodeID:1001, ServiceID:2(SHARD) }], rc: -105
  9. 2019-07-05-13.38.41.146227               Level:ERROR
  10. PID:7038                                 TID:7507
  11. Function:processMsg                      Line:1869
  12. File:SequoiaDB/engine/pmd/pmdProcessor.cpp
  13. Message:
  14. Error processing Agent request, rc=-105
  15. ...

Note：

每个协调节点只会记录通过自身连接进行请求的相关信息，用户需要确认请求通过哪个协调节点发出，以便于找到正确的日志信息。

2.找出发生异常的节点的详细信息。上一步骤中发现异常的节点是 “GroupID:1000, NodeID:1001”，用户可以通过查看分区组列表获取到该节点的详细信息。以下是返回的部分结果，通过分析可以判断发生异常的节点是 sdbserver2 机的 11820 节点：

  1. $  sdb 'db.list(SDB_LIST_GROUPS, {"GroupID" : 1000})'
  2. ...
  3. {
  4.   "HostName": "sdbserver2",
  5.   "Status": 1,
  6.   "dbpath": "/opt/sequoiadb/database/data/11820/",
  7.   "Service": [
  8.     {
  9.       "Type": 0,
  10.       "Name": "11820"
  11.     },
  12.     {
  13.       "Type": 1,
  14.       "Name": "11821"
  15.     },
  16.     {
  17.       "Type": 2,
  18.       "Name": "11822"
  19.     }
  20.   ],
  21.   "NodeID": 1001
  22. }
  23. ...

3.分析数据节点的诊断日志。以下为异常节点截取的部分日志内容，通过分析日志可以判断在连接 “sdbserver3:11821” 时失败，而 11821 端口时 11820 节点占用；节点的当前存活数量为：2，需要存活的节点数量为：3。

  1. ...
  2. 2019-07-05-13.38.27.749514               Level:ERROR
  3. PID:7046                                 TID:7336
  4. Function:syncConnect                     Line:358
  5. File:SequoiaDB/engine/net/netEventHandler.cpp
  6. Message:
  7. Connection[Handle:8] connect to sdbserver3:11821(11821) failed, rc: -79
  9. 2019-07-05-13.38.27.749565               Level:EVENT
  10. PID:7046                                 TID:7336
  11. Function:_sharingBeat                    Line:866
  12. File:SequoiaDB/engine/cls/clsReplicateSet.cpp
  13. Message:
  14. Reset node[1005] sharing-beat time to 1800(sec)
  16. 2019-07-05-13.38.41.142127               Level:ERROR
  17. PID:7046                                 TID:7554
  18. Function:_calculateW                     Line:4740
  19. File:SequoiaDB/engine/cls/clsShardSession.cpp
  20. Message:
  21. alive num[2] can not meet need[3]
  22. ...

4.查看集合的编目信息快照。通过 snapshot 接口查询集合的编目信息，下面是返回的部分结果。通过分析可以判断集合的的同步副本数 ReplSize 设置为3，即要求数据在写入三个副本后才返回成功：

  1.   > db.snapshot(SDB_SNAP_CATALOG, {"Name":"emp.employees"})
  2.   {
  3.     ...
  4.     "Name": "sample.employees",
  5.     "UniqueID": 17179869185,
  6.     "Version": 2,
  7.     "ReplSize": 3,
  8.     "Attribute": 0,
  9.     "AttributeDesc": "",
  10.     "ShardingKey": {
  11.       "_id": 1
  12.     }
  13.     ...
  14.   }

根据以上分析，可以得出结论：

  • 在数据插入时，数据只成功写入到两个副本，与该集合要求的三个副本不符，导致数据插入失败而抛出异常
  • 数据插入失败的节点是 sdbserver3 机器的 11820 节点，说明 sdbserver3 机器的 11820 节点下线