predixy icon indicating copy to clipboard operation
predixy copied to clipboard

Published 20 hours ago • verified publisher icon joyieldInc

With status 4 EventError

Open stillerrr opened this issue 7 years ago • 9 comments

predixy.log打印了这个日志，可以在哪里查询各种status的意思

stillerrr avatar Oct 11 '18 09:10 stillerrr

没有写文档，要去查看源码了，你可以贴出完整日志出来

fortrue avatar Oct 13 '18 00:10 fortrue

2018-10-11 17:18:11.404341 N Handler.cpp:212 h 417 remove c 10.160.xx.xx:xxxxx 18302 with status 4 EventError

stillerrr avatar Oct 13 '18 01:10 stillerrr

这个配合看一下客户端的报错是什么样的。另外predixy不需要配置这么多的线程，线程数超过机器的cpu核心数是没有意义的

fortrue avatar Oct 13 '18 02:10 fortrue

你这个问题后来解决了吗 我也遇到了

zxystack avatar Dec 02 '18 06:12 zxystack

我用redis-benchmark压测时也遇到这个问题了

压测命令：

# redis-benchmark -h 9.77.34.64 -p 32149 -c 50 -d 3 -n 10000000 -r 1048576
Writing to socket: Connection timed out
All clients disconnected... aborting.

查了下predixy的日志，里有一堆这类的报错：

2019-05-21 09:27:05.720599 N Handler.cpp:212 h 3 remove c 172.20.2.0:46783 19 with status 4 EventError
2019-05-21 09:27:05.720704 N Handler.cpp:212 h 1 remove c 172.20.2.0:46802 15 with status 4 EventError
2019-05-21 09:27:05.720729 N Handler.cpp:212 h 3 remove c 172.20.2.0:46810 13 with status 4 EventError
2019-05-21 09:27:05.720821 N Handler.cpp:212 h 2 remove c 172.20.2.0:46815 18 with status 4 EventError
2019-05-21 09:27:05.720833 N Handler.cpp:212 h 0 remove c 172.20.2.0:46823 14 with status 4 EventError
2019-05-21 09:27:05.720839 N Handler.cpp:212 h 1 remove c 172.20.2.0:46828 23 with status 4 EventError
2019-05-21 09:27:05.720844 N Handler.cpp:212 h 2 remove c 172.20.2.0:46817 11 with status 4 EventError
2019-05-21 09:27:05.720853 N Handler.cpp:212 h 1 remove c 172.20.2.0:46814 10 with status 4 EventError

急问怎么解？ @fortrue

jeremyxu2010 avatar May 21 '19 09:05 jeremyxu2010

我用redis-benchmark压测时也遇到这个问题了

压测命令：

# redis-benchmark -h 9.77.34.64 -p 32149 -c 50 -d 3 -n 10000000 -r 1048576
Writing to socket: Connection timed out
All clients disconnected... aborting.

查了下predixy的日志，里有一堆这类的报错：

2019-05-21 09:27:05.720599 N Handler.cpp:212 h 3 remove c 172.20.2.0:46783 19 with status 4 EventError
2019-05-21 09:27:05.720704 N Handler.cpp:212 h 1 remove c 172.20.2.0:46802 15 with status 4 EventError
2019-05-21 09:27:05.720729 N Handler.cpp:212 h 3 remove c 172.20.2.0:46810 13 with status 4 EventError
2019-05-21 09:27:05.720821 N Handler.cpp:212 h 2 remove c 172.20.2.0:46815 18 with status 4 EventError
2019-05-21 09:27:05.720833 N Handler.cpp:212 h 0 remove c 172.20.2.0:46823 14 with status 4 EventError
2019-05-21 09:27:05.720839 N Handler.cpp:212 h 1 remove c 172.20.2.0:46828 23 with status 4 EventError
2019-05-21 09:27:05.720844 N Handler.cpp:212 h 2 remove c 172.20.2.0:46817 11 with status 4 EventError
2019-05-21 09:27:05.720853 N Handler.cpp:212 h 1 remove c 172.20.2.0:46814 10 with status 4 EventError

急问怎么解？ @fortrue

看看压测时机器负载情况，是不是网卡打满了

fortrue avatar May 21 '19 11:05 fortrue

看看压测时机器负载情况，是不是网卡打满了

从两边的系统负载来看，并没有发现网卡被打满的情况 @fortrue

压测端：

# top -n 1

top - 10:03:30 up 7 days, 15 min,  4 users,  load average: 0.33, 0.40, 0.30
Tasks: 155 total,   1 running, 154 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.2 us,  0.4 sy,  0.0 ni, 99.3 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem : 16171844 total, 14155880 free,   810544 used,  1205420 buff/cache
KiB Swap:  2104508 total,  2104508 free,        0 used. 15191104 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                              
15643 root      20   0  123924  79948   1036 S  33.3  0.5   5:51.55 redis-benchmark             
...

# sar -u -r -q -d 3
Linux 3.10.107-1 	2019年05月22日 	_x86_64_	(8 CPU)

10时20分49秒     CPU     %user     %nice   %system   %iowait    %steal     %idle
10时20分52秒     all      0.65      0.00      4.35      0.00      0.00     95.00

10时20分49秒 kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit  kbactive   kbinact   kbdirty
10时20分52秒  14204648   1967196     12.16    153176    932192    753660      4.12   1293360    350368        96

10时20分49秒   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15   blocked
10时20分52秒         1       189      0.21      0.10      0.15         0

10时20分49秒       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
10时20分52秒  dev253-0      2.67      0.00     74.67     28.00      0.00      0.00      0.00      0.00
...

服务端：

# top -n 1

top - 10:04:06 up 6 days, 22:42,  3 users,  load average: 0.40, 0.49, 0.40
Tasks: 186 total,   1 running, 185 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.5 us,  0.3 sy,  0.0 ni, 99.1 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem : 16169228 total, 11370824 free,   645588 used,  4152816 buff/cache
KiB Swap:  2104508 total,  2104508 free,        0 used. 14376212 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                              
28606 root      20   0  165712   2540   1980 S  31.2  0.0  25:48.75 predixy                                                                                              
26439 root      20   0 1322552  86464  35792 S  18.8  0.5  18:31.87 kubelet                                                                                              
 6116 root      20   0   18552   9284    868 S  12.5  0.1   1:57.46 redis-server    
...

# sar -u -r -q -d 3
Linux 3.10.0-862.11.6.el7.x86_64 	2019年05月22日 	_x86_64_	(8 CPU)

10时19分31秒     CPU     %user     %nice   %system   %iowait    %steal     %idle
10时19分34秒     all      1.73      0.00      9.00      0.00      0.00     89.27

10时19分31秒 kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit  kbactive   kbinact   kbdirty
10时19分34秒  11367956   4801272     29.69    176960   3742744   4209128     23.03   3795072    572544       192

10时19分31秒   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15   blocked
10时19分34秒         0       583      0.42      0.45      0.47         0

10时19分31秒       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
10时19分34秒  dev253-0      2.33      0.00     53.33     22.86      0.00      0.14      0.14      0.03
10时19分34秒 dev253-16      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
...

jeremyxu2010 avatar May 22 '19 02:05 jeremyxu2010

看看压测时机器负载情况，是不是网卡打满了

从两边的系统负载来看，并没有发现网卡被打满的情况 @fortrue

压测端：

# top -n 1

top - 10:03:30 up 7 days, 15 min,  4 users,  load average: 0.33, 0.40, 0.30
Tasks: 155 total,   1 running, 154 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.2 us,  0.4 sy,  0.0 ni, 99.3 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem : 16171844 total, 14155880 free,   810544 used,  1205420 buff/cache
KiB Swap:  2104508 total,  2104508 free,        0 used. 15191104 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                              
15643 root      20   0  123924  79948   1036 S  33.3  0.5   5:51.55 redis-benchmark             
...

# sar -u -r -q -d 3
Linux 3.10.107-1 	2019年05月22日 	_x86_64_	(8 CPU)

10时20分49秒     CPU     %user     %nice   %system   %iowait    %steal     %idle
10时20分52秒     all      0.65      0.00      4.35      0.00      0.00     95.00

10时20分49秒 kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit  kbactive   kbinact   kbdirty
10时20分52秒  14204648   1967196     12.16    153176    932192    753660      4.12   1293360    350368        96

10时20分49秒   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15   blocked
10时20分52秒         1       189      0.21      0.10      0.15         0

10时20分49秒       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
10时20分52秒  dev253-0      2.67      0.00     74.67     28.00      0.00      0.00      0.00      0.00
...

服务端：

# top -n 1

top - 10:04:06 up 6 days, 22:42,  3 users,  load average: 0.40, 0.49, 0.40
Tasks: 186 total,   1 running, 185 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.5 us,  0.3 sy,  0.0 ni, 99.1 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem : 16169228 total, 11370824 free,   645588 used,  4152816 buff/cache
KiB Swap:  2104508 total,  2104508 free,        0 used. 14376212 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                              
28606 root      20   0  165712   2540   1980 S  31.2  0.0  25:48.75 predixy                                                                                              
26439 root      20   0 1322552  86464  35792 S  18.8  0.5  18:31.87 kubelet                                                                                              
 6116 root      20   0   18552   9284    868 S  12.5  0.1   1:57.46 redis-server    
...

# sar -u -r -q -d 3
Linux 3.10.0-862.11.6.el7.x86_64 	2019年05月22日 	_x86_64_	(8 CPU)

10时19分31秒     CPU     %user     %nice   %system   %iowait    %steal     %idle
10时19分34秒     all      1.73      0.00      9.00      0.00      0.00     89.27

10时19分31秒 kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit  kbactive   kbinact   kbdirty
10时19分34秒  11367956   4801272     29.69    176960   3742744   4209128     23.03   3795072    572544       192

10时19分31秒   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15   blocked
10时19分34秒         0       583      0.42      0.45      0.47         0

10时19分31秒       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
10时19分34秒  dev253-0      2.33      0.00     53.33     22.86      0.00      0.14      0.14      0.03
10时19分34秒 dev253-16      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
...

没看到网络使用情况

fortrue avatar May 22 '19 04:05 fortrue

@fortrue 花时间仔细查了一下，终于查明原因了，可以忽略该问题了 因为我是使用redis-operator将redis集群部署在kubernetes中的，在predixy配置文件里配置的rfs-cluster-name:26379，在测试时我尝试将redis集群的某些pod删除掉，这样redis集群中某些节点的ip发生变化了，因此predixy的日志里会不停地打印如下报错信息：

2019-05-21 09:27:05.720599 N Handler.cpp:212 h 3 remove c 172.20.2.0:46783 19 with status 4 EventError
2019-05-21 09:27:05.720704 N Handler.cpp:212 h 1 remove c 172.20.2.0:46802 15 with status 4 EventError

这里建议这类日志可以配置成打印N分钟，之后不再打印。

redis-benchmark突然中断的问题，最终查明这个环境虚拟机的网络有些问题，跟predixy本身无关。

# redis-benchmark -h 9.77.34.64 -p 32149 -c 50 -d 3 -n 10000000 -r 1048576
Writing to socket: Connection timed out
All clients disconnected... aborting.

jeremyxu2010 avatar May 25 '19 23:05 jeremyxu2010