怎么会产生大量日志 phxbinlogsvr 这个程序占CPU 也很高 3台机器群集 - Githubissues

Tencent / phxsql

A high availability MySQL cluster that guarantees data consistency between a master and slaves.

Other

2.47k stars 557 forks source link

怎么会产生大量日志 phxbinlogsvr 这个程序占CPU 也很高 3台机器群集 #140

Open hstom123 opened 7 years ago

hstom123 commented 7 years ago

917 08:26:54.338351 887 phx_glog.cpp:86] ERROR: httpcall -1 I0917 08:26:54.339787 829 phx_glog.cpp:86] ERR: sendReqHeader fail I0917 08:26:54.339792 829 phx_glog.cpp:86] ERROR: httpcall -1 E0917 08:26:54.341433 829 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.341608 829 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505661839 [0m I0917 08:26:54.341616 829 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.341883 887 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.341899 887 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505661839 [0m I0917 08:26:54.341907 887 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m I0917 08:26:54.452232 890 phx_glog.cpp:86] ERR: sendReqHeader fail I0917 08:26:54.452242 890 phx_glog.cpp:86] ERROR: httpcall -1 E0917 08:26:54.452749 890 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.452814 890 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505661839 [0m I0917 08:26:54.452823 890 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.453234 837 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.453253 837 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505661839 [0m I0917 08:26:54.453260 837 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.468785 747 phx_glog.cpp:78] [41;37m ERR: PN8phxpaxos12MessageEventE::ReConnect start, ip 192.168.65.132 [0m E0917 08:26:54.469521 747 phx_glog.cpp:78] [41;37m ERR: PN8phxpaxos9EventLoopE::OnError event error, events 28 socketfd 40 socket ip 192.168.65.132 errno 115 [0m I0917 08:26:54.556331 855 phx_glog.cpp:86] ERR: sendReqHeader fail I0917 08:26:54.556344 855 phx_glog.cpp:86] ERROR: httpcall -1 E0917 08:26:54.561993 855 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.562027 855 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505661839 [0m I0917 08:26:54.562309 855 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m I0917 08:26:54.565788 812 phx_glog.cpp:86] ERR: sendReqHeader fail I0917 08:26:54.565794 812 phx_glog.cpp:86] ERROR: httpcall -1 E0917 08:26:54.566920 812 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.567189 812 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505661839 [0m I0917 08:26:54.567200 812 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m I0917 08:26:54.667346 828 phx_glog.cpp:86] ERR: sendReqHeader fail I0917 08:26:54.667389 828 phx_glog.cpp:86] ERROR: httpcall -1 E0917 08:26:54.670013 747 phx_glog.cpp:78] [41;37m ERR: PN8phxpaxos12MessageEventE::ReConnect start, ip 192.168.65.132 [0m E0917 08:26:54.670051 747 phx_glog.cpp:78] [41;37m ERR: PN8phxpaxos9EventLoopE::OnError event error, events 28 socketfd 40 socket ip 192.168.65.132 errno 115 [0m I0917 08:26:54.675671 917 phx_glog.cpp:86] ERR: sendReqHeader fail I0917 08:26:54.675680 917 phx_glog.cpp:86] ERROR: httpcall -1 E0917 08:26:54.675722 828 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.675750 828 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505661839 [0m I0917 08:26:54.675758 828 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.678441 917 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 08:26:54.678462 917 phx_glog.cpp:78] [42;44m G

hstom123 commented 7 years ago

以上是两台机器如果增加到第三台 CPU 更高而且在/data/log 目录下产生大量日志估计一天硬盘都要满了，我在机器上什么也没操作数据库是空的，怎么会这样的？

wodesuck commented 7 years ago

看以上日志应该是你有一台机掉线了，所以会不断重试并打出很多日志。另外默认的loglevel配置是最高的，通过修改phxbinlogsvr.conf里的LogLevel选项，改成2或1可以减少日志数量。

hstom123 commented 7 years ago

I0917 20:17:02.714000 1003 phx_glog.cpp:86] ERROR: httpcall -303 E0917 20:17:02.716859 1003 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m E0917 20:17:02.716908 1003 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.132, master ip 192.168.65.130 version 400 expiretime 1505703480 [0m I0917 20:17:02.716920 1003 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505662861 [0m I0917 20:17:02.737887 1066 phx_glog.cpp:86] ERROR: httpcall -303 E0917 20:17:02.739258 1066 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m E0917 20:17:02.739399 1066 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.132, master ip 192.168.65.130 version 400 expiretime 1505703480 [0m I0917 20:17:02.739411 1066 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505662861 [0m I0917 20:17:02.877241 1002 phx_glog.cpp:86] ERROR: httpcall -303 E0917 20:17:02.878031 1002 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:02.878064 1002 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m I0917 20:17:02.878072 1002 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:02.887028 1004 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:02.887099 1004 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m E0917 20:17:02.890333 1004 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.132, master ip 192.168.65.130 version 400 expiretime 1505703480 [0m I0917 20:17:02.890348 1004 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 3 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m I0917 20:17:03.002673 926 phx_glog.cpp:86] [46;34m DoQuery mysql_query show variables like 'super_read_only'; done 0, [0m I0917 20:17:03.003011 926 phx_glog.cpp:86] [46;34m DoQuery mysql_query show status like 'Slave_running'; done 0, [0m I0917 20:17:03.003031 926 phx_glog.cpp:86] [46;34m CheckSlaveRunningStatus slave is running OFF [0m I0917 20:17:03.003144 926 phx_glog.cpp:86] [46;34m DoQuery mysql_query stop slave; done 0, [0m I0917 20:17:03.003248 926 phx_glog.cpp:86] [46;34m DoQuery mysql_query set global server_id=3232252292; done 0, [0m E0917 20:17:03.003263 926 phx_glog.cpp:78] [42;44m SlaveStart replica user has not been set, wait [0m I0917 20:17:03.003332 926 phx_glog.cpp:86] [46;34m CheckRunning check super read only ON is master 0 ret -2600 [0m I0917 20:17:03.003335 926 phx_glog.cpp:86] [46;34m Process check running ret -2600 [0m E0917 20:17:03.035754 1101 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:03.035790 1101 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662862 [0m E0917 20:17:03.035800 1101 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.132, master ip 192.168.65.130 version 400 expiretime 1505703480 [0m I0917 20:17:03.035807 1101 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 3 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m I0917 20:17:03.038729 1039 phx_glog.cpp:86] ERROR: httpcall -303 E0917 20:17:03.039335 1039 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662862 [0m E0917 20:17:03.039371 1039 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.132, master ip 192.168.65.130 version 400 expiretime 1505703480 [0m I0917 20:17:03.039381 1039 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505662862 [0m I0917 20:17:03.214047 1078 phx_glog.cpp:86] ERROR: httpcall -303 E0917 20:17:03.214094 1078 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:03.214161 1078 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m I0917 20:17:03.214170 1078 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:03.216312 1093 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:03.216341 1093 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m E0917 20:17:03.216351 1093 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.132, master ip 192.168.65.130 version 400 expiretime 1505703480 [0m I0917 20:17:03.229161 1093 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 3 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:03.287395 884 phx_glog.cpp:78] STATUS(0): PN8phxpaxos7CleanerE::run sleep a while, max deleted instanceid 0 checkpoint instanceid (no checkpoint) now instanceid 422 I0917 20:17:03.374887 1071 phx_glog.cpp:86] ERROR: httpcall -303 E0917 20:17:03.374938 1071 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:03.374969 1071 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m I0917 20:17:03.374977 1071 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:03.380129 1103 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:03.380156 1103 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m E0917 20:17:03.380165 1103 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.132, master ip 192.168.65.130 version 400 expiretime 1505703480 [0m I0917 20:17:03.380173 1103 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 3 get ip 192.168.65.130 version 400 expiretime 1505574120 [0m I0917 20:17:03.503608 1075 phx_glog.cpp:86] ERROR: httpcall -303 E0917 20:17:03.507215 1075 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m E0917 20:17:03.507249 1075 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.132, master ip 192.168.65.130 version 400 expiretime 1505703480 [0m I0917 20:17:03.507257 1075 phx_glog.cpp:86] [46;34m GetGlobalMaster resp num 2 get ip 192.168.65.130 version 400 expiretime 1505662861 [0m E0917 20:17:03.510120 1109 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.130, master ip 192.168.65.130 version 400 expiretime 1505574120 [0m E0917 20:17:03.510145 1109 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.131, master ip 192.168.65.130 version 400 expiretime 1505662861 [0m E0917 20:17:03.510154 1109 phx_glog.cpp:78] [42;44m GetGlobalMaster get data from ip 192.168.65.132, master ip 192.168.65.130 version 400 expiretime 1505703480 [0m I0917 20:17:03.510161 1109 phx_glog.cpp:86] [46;34m GetGloba

hstom123 commented 7 years ago

一样的结果机器全部连上一样消耗很大CPU 并且即使调整日志等级不显示这些日志了 CPU 一样是高高的占有

wodesuck commented 7 years ago

看你的日志里有一点很奇怪，从各机拿到的 expiretime 相差非常大，是不是时钟不一致，或者集群还有别的问题。另外，master 需要发送心跳包来进行续租，因此空闲期间也是会有一定占用的。不知道你这边测试环境具体是怎样，占用高是有多高。