killme2008/Metamorphosis

关于Comsumer重连问题

lnj2050 opened this issue · 5 comments

lnj2050 commented

在生产环境运行过程中，偶尔因为网络问题，导致Consumer一直报下面的错误
2014-08-28 13:21:53 ERROR SimpleFetchManager - 获取消息失败,topic=Disc,partition=0
com.taobao.metamorphosis.exception.MetaOpeartionTimeoutException: Send message timeout in 10000 mills
at com.taobao.metamorphosis.client.consumer.SimpleMessageConsumer.fetch(SimpleMessageConsumer.java:372) ~[metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.processRequest(SimpleFetchManager.java:227) [metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.run(SimpleFetchManager.java:215) [metamorphosis-client-1.4.6.2.jar:na]
at java.lang.Thread.run(Thread.java:662) [na:1.6.0_45]
2014-08-28 13:21:53 ERROR SimpleFetchManager - 获取消息失败,topic=Disc,partition=0
com.taobao.metamorphosis.exception.MetaOpeartionTimeoutException: Send message timeout in 10000 mills
at com.taobao.metamorphosis.client.consumer.SimpleMessageConsumer.fetch(SimpleMessageConsumer.java:372) ~[metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.processRequest(SimpleFetchManager.java:227) [metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.run(SimpleFetchManager.java:215) [metamorphosis-client-1.4.6.2.jar:na]
at java.lang.Thread.run(Thread.java:662) [na:1.6.0_45]

中间也进行了rebalance，从日志看也成功了。
2014-08-28 13:21:43 INFO ConsumerZooKeeper - begin rebalancing consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6 try #0
2014-08-28 13:21:44 WARN ConsumerZooKeeper - Consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1 with {Config=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525677558-3], StatusPoll=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525679271-4], Disc=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1], Event=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6], Perform=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986104-5], CollectSched=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2]} doesn't need to be rebalanced.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - end rebalancing consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1 try #0
2014-08-28 13:21:44 WARN ConsumerZooKeeper - rebalance success.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - Consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2 with {Config=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525677558-3], StatusPoll=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525679271-4], Disc=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1], Event=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6], Perform=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986104-5], CollectSched=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2]} doesn't need to be rebalanced.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - end rebalancing consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2 try #0
2014-08-28 13:21:44 WARN ConsumerZooKeeper - rebalance success.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - Consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6 with {Config=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525677558-3], StatusPoll=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525679271-4], Disc=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1], Event=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6], Perform=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986104-5], CollectSched=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2]} doesn't need to be rebalanced.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - end rebalancing consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6 try #0
2014-08-28 13:21:44 WARN ConsumerZooKeeper - rebalance success.

但从实际日志打印来看，一直在包这种问题，网络异常到恢复也就半个小时时间，但是这个异常从上周五一直打印到现在，说明Consumer重连还是存在一些问题

lnj2050 commented

另外，下面这个日志打印信息也有问题吧：
2014-08-28 13:21:53 ERROR SimpleFetchManager - 获取消息失败,topic=Disc,partition=0
com.taobao.metamorphosis.exception.MetaOpeartionTimeoutException: Send message timeout in 10000 mills
at com.taobao.metamorphosis.client.consumer.SimpleMessageConsumer.fetch(SimpleMessageConsumer.java:372) ~[metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.processRequest(SimpleFetchManager.java:227) [metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.run(SimpleFetchManager.java:215) [metamorphosis-client-1.4.6.2.jar:na]
at java.lang.Thread.run(Thread.java:662) [na:1.6.0_45]

这块我理解不应该是 Send message timeout in 10000 mills
而应该是 Receive message timeout in 10000 mills

allwmh commented

亲 您有没有即时通讯之类的联系方式呢？

------------------ 原始邮件 ------------------
发件人: "lnj2050";notifications@github.com;
发送时间: 2014年8月28日(星期四) 下午3:26
收件人: "killme2008/Metamorphosis"Metamorphosis@noreply.github.com;

主题: [Metamorphosis] 关于Comsumer重连问题 (#108)

在生产环境运行过程中，偶尔因为网络问题，导致Consumer一直报下面的错误
2014-08-28 13:21:53 ERROR SimpleFetchManager - 获取消息失败,topic=Disc,partition=0
com.taobao.metamorphosis.exception.MetaOpeartionTimeoutException: Send message timeout in 10000 mills
at com.taobao.metamorphosis.client.consumer.SimpleMessageConsumer.fetch(SimpleMessageConsumer.java:372) ~[metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.processRequest(SimpleFetchManager.java:227) [metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.run(SimpleFetchManager.java:215) [metamorphosis-client-1.4.6.2.jar:na]
at java.lang.Thread.run(Thread.java:662) [na:1.6.0_45]
2014-08-28 13:21:53 ERROR SimpleFetchManager - 获取消息失败,topic=Disc,partition=0
com.taobao.metamorphosis.exception.MetaOpeartionTimeoutException: Send message timeout in 10000 mills
at com.taobao.metamorphosis.client.consumer.SimpleMessageConsumer.fetch(SimpleMessageConsumer.java:372) ~[metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.processRequest(SimpleFetchManager.java:227) [metamorphosis-client-1.4.6.2.jar:na]
at com.taobao.metamorphosis.client.consumer.SimpleFetchManager$FetchRequestRunner.run(SimpleFetchManager.java:215) [metamorphosis-client-1.4.6.2.jar:na]
at java.lang.Thread.run(Thread.java:662) [na:1.6.0_45]

中间也进行了rebalance，从日志看也成功了。
2014-08-28 13:21:43 INFO ConsumerZooKeeper - begin rebalancing consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6 try #0
2014-08-28 13:21:44 WARN ConsumerZooKeeper - Consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1 with {Config=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525677558-3], StatusPoll=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525679271-4], Disc=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1], Event=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6], Perform=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986104-5], CollectSched=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2]} doesn't need to be rebalanced.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - end rebalancing consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1 try #0
2014-08-28 13:21:44 WARN ConsumerZooKeeper - rebalance success.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - Consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2 with {Config=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525677558-3], StatusPoll=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525679271-4], Disc=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1], Event=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6], Perform=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986104-5], CollectSched=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2]} doesn't need to be rebalanced.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - end rebalancing consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2 try #0
2014-08-28 13:21:44 WARN ConsumerZooKeeper - rebalance success.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - Consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6 with {Config=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525677558-3], StatusPoll=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525679271-4], Disc=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676090-1], Event=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6], Perform=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986104-5], CollectSched=[IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408525676825-2]} doesn't need to be rebalanced.
2014-08-28 13:21:44 WARN ConsumerZooKeeper - end rebalancing consumer IDCP-SHUOZHOU_sigmam-probe_10_210_19_52_10.210.19.52-7212-1408526986226-6 try #0
2014-08-28 13:21:44 WARN ConsumerZooKeeper - rebalance success.

但从实际日志打印来看，一直在包这种问题，网络异常到恢复也就半个小时时间，但是这个异常从上周五一直打印到现在，说明Consumer重连还是存在一些问题

—
Reply to this email directly or view it on GitHub.

lnj2050 commented

qq: 24614577

allwmh commented

云 你+我吧 497055733

------------------ 原始邮件 ------------------
发件人: "lnj2050"notifications@github.com;
发送时间: 2014年8月28日(星期四) 下午3:49
收件人: "killme2008/Metamorphosis"Metamorphosis@noreply.github.com;
抄送: "allwmh"allwmh@gmail.com;
主题: Re: [Metamorphosis] 关于Comsumer重连问题 (#108)

qq: 24614577

—
Reply to this email directly or view it on GitHub.

muyunisawesome commented

这个问题我也遇到了，请问怎么解决啊。 打出log4j日志，显示
[2016-06-22 16:08:57,559] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
[2016-06-22 16:08:57,559] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
[2016-06-22 16:08:57,560] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
[2016-06-22 16:08:57,560] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
[2016-06-22 16:08:57,560] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
[2016-06-22 16:08:57,560] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
[2016-06-22 16:08:57,560] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
consumer那边就是各种getmessage超时