Star

nebula数据库负载异常

基本信息

  • nebula 版本:nebula 7weeks ago的版本,具体的版本号没找到 :slight_smile:
  • 部署方式:单机docker-compose
docker images
REPOSITORY                   TAG                 IMAGE ID            CREATED             SIZE
vesoft/nebula-console        nightly             c534e10aeb57        7 weeks ago         249MB
vesoft/nebula-metad          nightly             540e260c1431        7 weeks ago         288MB
vesoft/nebula-storaged       nightly             296b06c25991        7 weeks ago         288MB
vesoft/nebula-graphd         nightly             511f2adcfb7e        7 weeks ago         282MB
  • 硬件信息
    • 磁盘(SSD / HDD): hdd 2T*5,lvm合并为一个逻辑磁盘
    • CPU、内存信息:40C 189GB
  • 出问题的 Space 的创建方式:执行 describe space xxx;
=============================================================================
| ID | Name        | Partition number | Replica Factor | Charset | Collate  |
=============================================================================
| 34 |  Topology | 100              | 1              | utf8    | utf8_bin |
-----------------------------------------------------------------------------
Got 1 rows (Time spent: 442.754/444.4 ms)

问题的具体描述

服务器负载异常

load average: 90.27, 93.43, 95.97

在 nebula-cli中执行show spaces类的系统命令可以正常执行,但是执行fetch prop类的查询命令会阻塞,最后返回查询失败

(user@nebula) [IP_Topology]> fetch prop on sometag 12324;
[ERROR (-8)]: Get tag props failed
Tue Oct 27 01:15:51 2020

分析发现 cpu空闲,内存一共189GB,已使用80GB,SWAP大小16G,占满,磁盘IO一直有读写

此处有疑问是为什么内存大量空闲但是不占用内存,而是要写入到swap中,推测是数据库想要将数据写入到swap,但是swap大小不足导致写入失败导致阻塞。但是swap是写到了硬盘上,读写速度太慢,请问有办法控制他写入swap的策略么,比如我希望尽量占用内存,当内存满之后再写swap。

另外目前是使用docker单机部署的,参数都是使用默认的设置,看了文档里面关于参数的描述,可能我们本机需要做参数的修改,请问有推荐的参数设置么?

$ vmstat

$ top

我觉得,你应该首先找出fetch 失败的原因。
可以看一下log, 看看是什么原因导致的失败。

dstat 看下,如果你没做什么操作,怎么会swap那么高。
top按内存使用排序看下。
应该是环境问题。

另外为什么要用2个月前的测试版本,release版本也有啊。

使用 nebula-python和数据库交互,python抛出 timeout

  File "/usr/local/lib/python3.8/site-packages/nebula/Client.py", line 117, in execute_query
    raise ExecutionException("Execute `{}' failed: {}".format(statement, x))
 nebula.Common.ExecutionException: Execute `GO FROM 217 OVER someedge YIELD $$.sometag.name' failed: Socket read failed: timed out
 Traceback (most recent call last):
   File "/usr/local/lib/python3.8/site-packages/thrift/transport/TSocket.py", line 298, in read
     buff = self.handle.recv(sz)
 socket.timeout: timed out

查看日志可以看到里面有Timed Out的异常

graphd的日志

$ tail  graph/nebula-graphd.INFO 
I1027 03:27:28.835041    94 UseExecutor.cpp:48] Graph space switched to `TEST', space id: 34
I1027 03:27:49.888263    94 GraphService.cpp:50] Authenticating user user from 10.10.10.131:58192
I1027 03:27:52.192646    78 GraphService.cpp:50] Authenticating user user from 10.10.10.131:58196
I1027 03:27:52.194272    78 UseExecutor.cpp:48] Graph space switched to `TEST', space id: 34
E1027 03:28:29.368170    16 StorageClient.inl:123] Request to [172.28.2.2:44500] failed: N6apache6thrift9transport19TTransportExceptionE: Timed Out
E1027 03:28:29.368497    16 StorageClient.inl:123] Request to [172.28.2.3:44500] failed: N6apache6thrift9transport19TTransportExceptionE: Timed Out
E1027 03:28:29.368639    16 StorageClient.inl:123] Request to [172.28.2.1:44500] failed: N6apache6thrift9transport19TTransportExceptionE: Timed Out
E1027 03:28:29.368840    81 ExecutionPlan.cpp:80] Execute failed: Get dest props failed
E1027 03:28:52.204252    22 StorageClient.inl:123] Request to [172.28.2.1:44500] failed: N6apache6thrift9transport19TTransportExceptionE: Timed Out
E1027 03:28:52.204530    78 ExecutionPlan.cpp:80] Execute failed: Get neighbors failed

其中一个storage的日志

$ tail  storage0/nebula-storaged.INFO -n 20
I1027 03:30:22.826171    70 CompactionFilter.h:67] Do default minor compaction!
I1027 03:30:45.781060    70 EventListner.h:33] Rocksdb compact column family: default because of 1, status: OK, compacted 15 files into 8, base level is 0, output level is 1
I1027 03:30:46.804128    70 EventListner.h:23] Rocksdb compact column family: default because of 2, status: OK, compacted 5 files into 0, base level is 1, output level is 2
I1027 03:30:46.804448    70 CompactionFilter.h:67] Do default minor compaction!
I1027 03:30:47.997128    26 InMemoryLogBuffer.h:27] [Port: 44501, Space: 63, Part: 84] InMemoryLogBuffer dtor, firstLogId 3639252
I1027 03:30:48.001283    26 InMemoryLogBuffer.h:23] [Port: 44501, Space: 63, Part: 84] InMemoryLogBuffer ctor, firstLogId 3661806
I1027 03:30:49.721815    64 SlowOpTracker.h:33] [Port: 44501, Space: 59, Part: 9] , total time:207ms, Write WAL, total 2
I1027 03:30:49.722144    66 SlowOpTracker.h:33] [Port: 44501, Space: 59, Part: 45] , total time:207ms, Write WAL, total 2
I1027 03:30:49.723392    67 SlowOpTracker.h:33] [Port: 44501, Space: 59, Part: 57] , total time:209ms, Write WAL, total 2
I1027 03:30:50.502573    14 SlowOpTracker.h:33] [Port: 44501, Space: 51, Part: 45] , total time:180ms, Total commit: 1
I1027 03:30:52.897030    42 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 60] , total time:203ms, Write WAL, total 2
I1027 03:30:53.362690    42 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 24] , total time:431ms, Write WAL, total 2
I1027 03:30:53.804636    41 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 63] , total time:69ms, Write WAL, total 2
I1027 03:30:53.804633    24 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 57] , total time:70ms, Write WAL, total 2
I1027 03:30:53.804641    21 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 72] , total time:69ms, Write WAL, total 2
I1027 03:30:53.804642    22 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 51] , total time:70ms, Write WAL, total 2
I1027 03:30:53.804649    26 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 66] , total time:71ms, Write WAL, total 2
I1027 03:30:53.804652    39 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 48] , total time:71ms, Write WAL, total 2
I1027 03:30:53.804726    37 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 69] , total time:70ms, Write WAL, total 2
I1027 03:30:53.804859    13 SlowOpTracker.h:33] [Port: 44501, Space: 63, Part: 45] , total time:71ms, Write WAL, total 2

dstat 看下,如果你没做什么操作,怎么会swap那么高。

你好,看 dstat 的输出看起来是磁盘一直有读写 机器的磁盘是HDD 2T*5 做的 lvm,可能比较容易到瓶颈。

dstat -cdngy
--total-cpu-usage-- -dsk/total- -net/total- ---paging-- ---system--
usr sys idl wai stl| read  writ| recv  send|  in   out | int   csw 
 26   3  64   6   0|9644k   22M|   0     0 | 911B   51k|  12k   38k
 17   5  74   3   0|8692k   61M|  18M   35M|   0     0 |  24k  185k
  4   4  90   3   0| 380k   26M|1476B  404B|   0     0 |  11k 2477 
 18   4  72   5   0|7948k   93M|  18M   36M|   0     0 |  21k  187k
  4   0  90   6   0|1184k   87M|2335k 4586k|   0     0 |4598    25k
 21   5  70   4   0|8452k   19M|  20M   39M|   0    24k|  22k  193k
  2   3  90   5   0| 444k   93M|1374B  358B|   0    36k|  11k 2970 
 19   5  73   4   0|9276k  107M|  22M   43M|   0     0 |  29k  211k
 23   5  69   4   0|  21M   39M|  22M   43M|   0     0 |  26k  210k
 17   5  76   3   0|  30M   63M|  14M   27M|   0     0 |  22k  134k
  4   3  90   4   0|4760k   68M|2226B  697B|   0     0 |  11k 2375 
 17   3  76   4   0|5236k   86M|  13M   26M|   0     0 |  22k  129

top按内存使用排序看下。

按内存和CPU排序的 top


另外为什么要用2个月前的测试版本,release版本也有啊。

两个月前部署的机器,考虑着部署方便直接就起了github提供的docker-compose模板,也没有调整参数就上了 :slight_smile:

今早发了帖子之后把 swap 扩大到了 50G,操作之后负载在一直缓慢下降,但是 swap 的占用却没有多大变化,还是 15GB
最近十分钟内没有对数据库做 读写操作,但是 graphd 负载较高

$ show hosts

(user@nebula) [Topology]> show hosts;
==================================================================================================================================================================================================================================================================================
| Ip         | Port  | Status | Leader count | Leader distribution
  | Partition distribution                                                                                          |
==================================================================================================================================================================================================================================================================================
| 172.28.2.1 | 44500 | online | 198          | Topology: 33, Topology_Rich: 33, TEST_CCCC: 33, Topology_Dynamic: 33, TEST: 33, SOMEDB: 33
  | SOMEDB: 33, Topology: 33, Topology_Rich: 33, TEST: 33, Topology_Dynamic: 33, TEST_CCCC: 33       |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| 172.28.2.2 | 44500 | online | 204          | Topology: 34, Topology_Rich: 34, TEST_CCCC: 34, Topology_Dynamic: 34, TEST: 34, SOMEDB: 34
  | SOMEDB: 34, Topology: 34, Topology_Rich: 34, TEST: 34, Topology_Dynamic: 34, TEST_CCCC: 34       |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| 172.28.2.3 | 44500 | online | 198          | Topology: 33, Topology_Rich: 33, TEST_CCCC: 33, Topology_Dynamic: 33, TEST: 33, SOMEDB: 33
  | SOMEDB: 33, Topology: 33, Topology_Rich: 33, TEST: 33, Topology_Dynamic: 33, TEST_CCCC: 33       |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Total      |       |        | 600          | SOMEDB: 100, Topology_Rich: 100, Topology: 100, TEST_CCCC: 100, Topology_Dynamic: 100, TEST: 100 | TEST_CCCC: 100, Topology: 100, Topology_Rich: 100, SOMEDB: 100, TEST: 100, Topology_Dynamic: 100 |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Got 4 rows (Time spent: 1.98/3.816 ms)

Tue Oct 27 05:48:50 2020

看上去机械盘完全搞不动啊,为什么持续有这么多disk write,是一直在compaction做不完了?

你用了几台机器,每个机器部署了几个storaged?

你还是先换release 1.1吧,nightly的问题很可能是已修复的。

另外,我的经验是机械盘基本跑不出性能的。

1台机器,3个storaged,参数都没改,直接用的仓库的docker-compose.yaml
https://github.com/vesoft-inc/nebula-docker-compose

抱歉,刚刚得知我执行 dstat 命令的时候后台新开了个导入任务,造成了比较高的持续写入的问题,影响了此处的判断。 :stuck_out_tongue:

早晨提问的时候的 vmstat 的命令的输出是没有执行其他任务的情况下 磁盘的 io 情况,每秒读2000个块左右,写500个块.

请问有没有推荐的迁移的方式,库里面目前大概有20亿个节点,我使用 db_dump 工具导出来大约有300GB+,但是这个结果似乎不能直接导入到新的nebula中,还需要二次处理才可以

  1. 直接升级rpm或者docker版本就行了,不用导出来,数据格式是兼容的。

  2. 一台物理机其实部署一个storaged就够了,多了没啥用。 这个文件示意其实是给多个机器ip的情况。
    3个storaged之间还得rpc,有点浪费性能。

好的 ,我稍后尝试升级,看看能不能解决这个问题,谢谢~

建议放一个 best practice 版本的 docker-compose在 https://docs.nebula-graph.com.cn/manual-CN/3.build-develop-and-administration/2.install/3.install-with-docker/ 这里面,或者在文档说明一下这里面为什么开这么多个实例的原因 :slight_smile:

2赞

docker-compose up之前先看下物理机swap啥情况。

因为 nebula 还承载着业务,短期内可能不会重启数据库 :frowning:
我先尝试用 v1.1.0 新开一个机器,把数据导出来再导进去,之后再做故障排查吧 :slight_smile:

问题暂时告一段落,感谢各位的回复 :slight_smile:

2赞

get,我目前也是原始版本,怕升级后出问题,暂时就不动了

这么高的swap,nightly版本,运行生产?这是时刻准备救(pao)火(lu)的节奏啊。

目前正在部署新的机器,准备导入数据,希望不会出问题吧 :slight_smile:

1赞

image

1赞

数据迁移完成,新开了一台虚拟机分的 8c 64G 2T hdd, docker-compose部署运行 v1.1.0,storaged/metad/graphd 各一个,replica=1 :upside_down_face:

在刚导入完之后似乎有个重新均衡负载的过程,磁盘读写比较高,大约完成之后的几个小时cpu占用降低到0,稳定之后硬盘占用 98G,内存 20G

btw,导入过程中发现 nebula_importer 读取超过2万行的 config.yaml 会读取失败 ,人工拆分到2000行就可以正常运行了

上线上线 :slight_smile:

2赞

麻烦问一下 nebula-importer 读取大文件失败的原因是什么?有什么错误输出吗?

提了个issue

1赞

浙ICP备20010487号