Kube-router: ipvs rule sync stoped with the error " genl hub loop exit"!

[huxos]

kube-router : v0.0.9 (image: cloudnativelabs/kube-router:v0.0.9)
kernel: Linux kube-system-4 4.10.0-27-generic #30~16.04.2-Ubuntu SMP Thu Jun 29 16:07:46 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
os: Ubuntu 16.04.2 LTS
k8s: v1.7.1
docker: 1.12.6

====================
args: --run-service-proxy=true --cluster-cidr=10.99.66.0/23 --ipvs-sync-period=30s --run-router=false --run-firewall=false

here is the kube-router log

I0727 05:14:32.513590       1 network_services_controller.go:677] ipvs service 10.99.67.139:tcp:8080 already exists so returning
I0727 05:14:32.513750       1 network_services_controller.go:714] ipvs destination 10.100.2.6:8080 already exists in the ipvs service 10.99.67.139:tcp:8080 so not adding destination
I0727 05:14:32.514754       1 network_services_controller.go:677] ipvs service 10.99.67.192:tcp:80 already exists so returning
I0727 05:14:32.514912       1 network_services_controller.go:714] ipvs destination 10.100.2.3:9090 already exists in the ipvs service 10.99.67.192:tcp:80 so not adding destination
I0727 05:14:32.515904       1 network_services_controller.go:677] ipvs service 10.99.67.156:tcp:22 already exists so returning
I0727 05:14:32.516901       1 network_services_controller.go:677] ipvs service 10.33.109.93:tcp:30641 already exists so returning
I0727 05:14:32.517837       1 network_services_controller.go:677] ipvs service 10.99.66.244:tcp:80 already exists so returning
I0727 05:14:32.518760       1 network_services_controller.go:677] ipvs service 10.99.66.1:tcp:443 already exists so returning
I0727 05:14:32.518918       1 network_services_controller.go:714] ipvs destination 10.33.109.20:6443 already exists in the ipvs service 10.99.66.1:tcp:443 so not adding destination
I0727 05:14:32.519029       1 network_services_controller.go:714] ipvs destination 10.33.109.79:6443 already exists in the ipvs service 10.99.66.1:tcp:443 so not adding destination
I0727 05:14:32.519128       1 network_services_controller.go:714] ipvs destination 10.33.109.92:6443 already exists in the ipvs service 10.99.66.1:tcp:443 so not adding destination
I0727 05:14:32.520009       1 network_services_controller.go:677] ipvs service 10.99.67.177:tcp:9090 already exists so returning
I0727 05:14:32.520907       1 network_services_controller.go:677] ipvs service 10.33.109.93:tcp:30900 already exists so returning
I0727 05:14:32.521815       1 network_services_controller.go:677] ipvs service 10.99.67.28:tcp:3306 already exists so returning
I0727 05:14:32.521967       1 network_services_controller.go:714] ipvs destination 10.100.2.9:3306 already exists in the ipvs service 10.99.67.28:tcp:3306 so not adding destination
I0727 05:14:32.522782       1 network_services_controller.go:677] ipvs service 10.99.67.250:tcp:9093 already exists so returning
I0727 05:14:32.523648       1 network_services_controller.go:677] ipvs service 10.33.109.93:tcp:30903 already exists so returning
I0727 05:14:32.523795       1 network_services_controller.go:714] ipvs destination 10.100.2.5:9093 already exists in the ipvs service 10.99.67.250:tcp:9093 so not adding destination
I0727 05:14:32.523899       1 network_services_controller.go:714] ipvs destination 10.100.2.5:9093 already exists in the ipvs service 10.33.109.93:tcp:30903 so not adding destination
I0727 05:14:32.524743       1 network_services_controller.go:677] ipvs service 10.99.67.31:tcp:443 already exists so returning
I0727 05:14:32.524867       1 network_services_controller.go:714] ipvs destination 10.100.8.51:443 already exists in the ipvs service 10.99.67.31:tcp:443 so not adding destination
I0727 05:14:32.525687       1 network_services_controller.go:677] ipvs service 10.99.66.234:tcp:44134 already exists so returning
I0727 05:14:32.525812       1 network_services_controller.go:714] ipvs destination 10.100.2.10:44134 already exists in the ipvs service 10.99.66.234:tcp:44134 so not adding destination
I0727 05:14:32.525826       1 network_services_controller.go:291] Cleaning up if any, old ipvs service and servers which are no longer needed
2017/07/27 05:14:32` genl hub loop exit`

===============================================

[murali-reddy]

@huxos thanks for reporting bug. I am not able to reproduce on Ubuntu 16.4, k8s: v1.7. with kube-router v0.0.9. Do you observe this behaviour immediately or after some period of time?

Also does kube-router stop functioning totally? error 'genl hub loop exit' seems not to have any fatal behaviour

[huxos]

it's after some period of time. kube-router seems stop functioning totally without any log for endpoints changing. but another instance whithout the err "genl hub loop exit" works fine .

[murali-reddy]

thanks @huxos i will do some long running tests and try to figure the cause.

[bzub]

Looking at the nlgo code it seems like the for loop is not supposed to exit unless there's a syscall error or the program exits. Unfortunately the errors are never passed on, so we might consider creating a PR upstream and maybe build a version of kube-router with those changes to the library for @huxos to use temporarily, since I cannot reproduce this either yet.

@huxos It's possible a kernel message is logged when this issue pops up. Please check dmesg or sudo journalctl -k after the bug appears, if you haven't already.

[huxos]

I have checked the kernel message, but there is nothing for this issue.

here is the kernel log at that time (UTC+8) on the host

Jul 27 11:27:44 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:49 kube-system-2 kernel: net_ratelimit: 82 callbacks suppressed
Jul 27 11:27:49 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:50 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:50 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:50 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:50 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:50 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:50 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:50 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:50 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:27:50 kube-system-2 kernel: IPVS: rr: TCP 10.99.67.69:6379 - no destination available
Jul 27 11:32:01 kube-system-2 kernel: ixgbe 0000:04:00.1: registered PHC device on enp4s0f1
Jul 27 11:32:02 kube-system-2 kernel: ixgbe 0000:04:00.1 enp4s0f1: detected SFP+: 6
Jul 27 11:39:15 kube-system-2 kernel: perf: interrupt took too long (3145 > 3130), lowering kernel.perf_event_max_sample_rate to 63500
Jul 27 11:44:37 kube-system-2 kernel: ixgbe 0000:04:00.1 enp4s0f1: NIC Link is Up 10 Gbps, Flow Control: RX/TX
Jul 27 15:36:54 kube-system-2 kernel: Netfilter messages via NETLINK v0.30.
Jul 27 15:36:54 kube-system-2 kernel: ctnetlink v0.93: registering with nfnetlink.
Jul 27 22:58:22 kube-system-2 kernel: perf: interrupt took too long (3939 > 3931), lowering kernel.perf_event_max_sample_rate to 50750
Jul 28 11:21:48 kube-system-2 systemd[1]: apt-daily.timer: Adding 2h 35min 26.110517s random time.
Jul 28 11:21:51 kube-system-2 kernel: audit: type=1400 audit(1501212111.959:18): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="docker-default" pid=32238 comm="appar
Jul 28 15:04:58 kube-system-2 kernel: JFS: nTxBlock = 8192, nTxLock = 65536
Jul 28 15:04:58 kube-system-2 kernel: ntfs: driver 2.1.32 [Flags: R/O MODULE].
Jul 28 15:04:58 kube-system-2 kernel: QNX4 filesystem 0.2.3 registered.

[murali-reddy]

@huxos i am able to reproduce the issue please see #93 i will work out a fix.

[bzub]

@huxos If possible, please test the cloudnativelabs/kube-router-git:PR101 container image. It should fix the issue. If you see log formatting bugs it is a known cosmetic issue at this time. Thanks!

[huxos]

good job, it's worked.