Big Packet lose in K8s (二)
新的征程在第一篇定位 K8s环境中打包丢失的问题的时候,我们定位到 eth0收到了No.9 报文,但是 flannel.1 中丢失了No.9 报文。那么在 eth0 到 flannel.1 之间,到底经过了什么处理,为什么丢包了呢?因为我们配置K8s的 nodeport service 将外部30063端口 转换为 内部 3000端口,而service 的功能是由iptables...
新的征程
- 在第一篇定位 K8s环境中打包丢失的问题的时候,我们定位到 eth0收到了No.9 报文,但是 flannel.1 中丢失了No.9 报文。
- 那么在 eth0 到 flannel.1 之间,到底经过了什么处理,为什么丢包了呢?
- 因为我们配置K8s的 nodeport service 将外部30063端口 转换为 内部 3000端口,而service 的功能是由iptables实现的,所以我们将所有的矛头都指向了iptables
问题分析
1. 先看一下K8s 是怎么利用iptables 来进行端口映射的 30063 -> 3000
ps: iptables的语法规则真TMD繁琐, K8s在里面又增加了百来条的规则
- 以上是从浩如烟海的规则中抽取出来的几条,可以看出利用 iptables的 DNAT 方法,将所有收到的 dport = 30063的报文,都转换为 10.244.1.17:3000
- 从规则中没看出任何毛病,理论上iptables也不应该会有
小包通过,大包不过
的情况发生 - 但实在没有头绪,只能硬着头皮看看有没有iptabels 的debug手段了
2. Trace iptables
一通Google操作,还真找到了Debug iptables 的方法
细节不赘述了,可以参考后面链接
iptables -t raw -A OUTPUT -d 10.244.1.17 -j TRACE
iptables -t raw -A PREROUTING -d 10.244.1.17 -j TRACE
modprobe ipt_LOG
modprobe nf_log_ipv4
sysctl net.netfilter.nf_log.2=nf_log_ipv4
2.1 小包日志日志
Jul 21 00:28:06 10-10-99-144 kernel: TRACE: raw:PREROUTING:policy:2 IN=cni0 OUT= PHYSIN=vethe57aa284 MAC=0a:58:0a:f4:00:01:0a:58:0a:f4:00:1a:08:00 SRC=10.244.0.26 DST=10.244.2.207 LEN=149 TOS=0x00 PREC=0x00 TTL=64 ID=64398 DF PROTO=UDP SPT=53 DPT=48865 LEN=129
Jul 21 00:28:06 10-10-99-144 kernel: TRACE: filter:FORWARD:rule:1 IN=cni0 OUT=flannel.1 PHYSIN=vethe57aa284 MAC=0a:58:0a:f4:00:01:0a:58:0a:f4:00:1a:08:00 SRC=10.244.0.26 DST=10.244.2.207 LEN=149 TOS=0x00 PREC=0x00 TTL=63 ID=64398 DF PROTO=UDP SPT=53 DPT=48865 LEN=129
Jul 21 00:28:06 10-10-99-144 kernel: TRACE: filter:KUBE-FORWARD:rule:2 IN=cni0 OUT=flannel.1 PHYSIN=vethe57aa284 MAC=0a:58:0a:f4:00:01:0a:58:0a:f4:00:1a:08:00 SRC=10.244.0.26 DST=10.244.2.207 LEN=149 TOS=0x00 PREC=0x00 TTL=63 ID=64398 DF PROTO=UDP SPT=53 DPT=48865 LEN=129
Jul 21 00:28:06 10-10-99-144 kernel: TRACE: raw:PREROUTING:policy:2 IN=cni0 OUT= PHYSIN=vethe57aa284 MAC=0a:58:0a:f4:00:01:0a:58:0a:f4:00:1a:08:00 SRC=10.244.0.26 DST=10.244.2.207 LEN=111 TOS=0x00 PREC=0x00 TTL=64 ID=64399 DF PROTO=UDP SPT=53 DPT=48865 LEN=91
Jul 21 00:28:06 10-10-99-144 kernel: TRACE: filter:FORWARD:rule:1 IN=cni0 OUT=flannel.1 PHYSIN=vethe57aa284 MAC=0a:58:0a:f4:00:01:0a:58:0a:f4:00:1a:08:00 SRC=10.244.0.26 DST=10.244.2.207 LEN=111 TOS=0x00 PREC=0x00 TTL=63 ID=64399 DF PROTO=UDP SPT=53 DPT=48865 LEN=91
Jul 21 00:28:06 10-10-99-144 kernel: TRACE: filter:KUBE-FORWARD:rule:2 IN=cni0 OUT=flannel.1 PHYSIN=vethe57aa284 MAC=0a:58:0a:f4:00:01:0a:58:0a:f4:00:1a:08:00 SRC=10.244.0.26 DST=10.244.2.207 LEN=111 TOS=0x00 PREC=0x00 TTL=63 ID=64399 DF PROTO=UDP SPT=53 DPT=48865 LEN=91
2.2 大包日志
Jul 21 00:30:09 10-10-99-144 kernel: ------------[ cut here ]------------
Jul 21 00:30:09 10-10-99-144 kernel: WARNING: CPU: 1 PID: 0 at net/core/dev.c:2496 skb_warn_bad_offload+0xcd/0xda
Jul 21 00:30:09 10-10-99-144 kernel: : caps=(0x00003021001b5889, 0x0000000000000000) len=1464 data_len=1336 gso_size=1398 gso_type=5 ip_summed=1
Jul 21 00:30:09 10-10-99-144 kernel: Modules linked in: nf_log_ipv4 nf_log_common xt_TRACE xt_LOG iptable_raw xt_statistic binfmt_misc nfnetlink_queue nfnetlink_log bluetooth loop cfg80211 rfkill nf_conntrack_netlink veth vxlan ip6_udp_tunnel udp_tunnel xt_nat xt_recent ipt_REJECT nf_reject_ipv4 ip_set nfnetlink xt_comment xt_mark ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype iptable_filter xt_conntrack nf_nat nf_conntrack br_netfilter bridge stp llc overlay(T) sunrpc joydev sg ppdev virtio_balloon parport_pc i2c_piix4 parport pcspkr ip_tables xfs libcrc32c sr_mod cdrom ata_generic pata_acpi virtio_net virtio_console virtio_scsi virtio_blk cirrus drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm drm ata_piix libata virtio_pci virtio_ring serio_raw
Jul 21 00:30:09 10-10-99-144 kernel: floppy i2c_core virtio dm_mirror dm_region_hash dm_log dm_mod
Jul 21 00:30:09 10-10-99-144 kernel: CPU: 1 PID: 0 Comm: swapper/1 Tainted: G W ------------ T 3.10.0-693.el7.x86_64 #1
Jul 21 00:30:09 10-10-99-144 kernel: Hardware name: Red Hat KVM, BIOS seabios-1.7.5-11.el7 04/01/2014
Jul 21 00:30:09 10-10-99-144 kernel: ffff88043fc439a0 a3eaaf6a30ee44fa ffff88043fc43950 ffffffff816a3d91
Jul 21 00:30:09 10-10-99-144 kernel: ffff88043fc43990 ffffffff810879c8 000009c0a6fd2cb2 ffff8803e6346100
Jul 21 00:30:09 10-10-99-144 kernel: ffff88041e2fa000 0000000000000005 0000000000000001 0000000000000004
Jul 21 00:30:09 10-10-99-144 kernel: Call Trace:
Jul 21 00:30:09 10-10-99-144 kernel: <IRQ> [<ffffffff816a3d91>] dump_stack+0x19/0x1b
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff810879c8>] __warn+0xd8/0x100
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81087a4f>] warn_slowpath_fmt+0x5f/0x80
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81329233>] ? ___ratelimit+0x93/0x100
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff816a6004>] skb_warn_bad_offload+0xcd/0xda
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81588c25>] __skb_gso_segment+0x105/0x150
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81589025>] validate_xmit_skb.isra.102.part.103+0x135/0x2e0
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815897f0>] __dev_queue_xmit+0x4b0/0x550
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815898a0>] dev_queue_xmit+0x10/0x20
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815cfd3e>] ip_finish_output+0x52e/0x780
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815d0293>] ip_output+0x73/0xe0
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815cf810>] ? __ip_append_data.isra.48+0xa00/0xa00
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815cbcf6>] ip_forward_finish+0x66/0x80
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815cc08c>] ip_forward+0x37c/0x480
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815cbc90>] ? ip_frag_mem+0x40/0x40
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815c9cda>] ip_rcv_finish+0x8a/0x350
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815ca666>] ip_rcv+0x2b6/0x410
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff815c9c50>] ? inet_del_offload+0x40/0x40
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81586f22>] __netif_receive_skb_core+0x572/0x7c0
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff810ea8ca>] ? __getnstimeofday64+0x3a/0xd0
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81587188>] __netif_receive_skb+0x18/0x60
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81587210>] netif_receive_skb_internal+0x40/0xc0
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81588318>] napi_gro_receive+0xd8/0x130
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffffc008d505>] virtnet_poll+0x265/0x750 [virtio_net]
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff8158799d>] net_rx_action+0x16d/0x380
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81090b3f>] __do_softirq+0xef/0x280
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff816b6a5c>] call_softirq+0x1c/0x30
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff8102d3c5>] do_softirq+0x65/0xa0
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81090ec5>] irq_exit+0x105/0x110
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff816b75f6>] do_IRQ+0x56/0xe0
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff816ac1ed>] common_interrupt+0x6d/0x6d
Jul 21 00:30:09 10-10-99-144 kernel: <EOI> [<ffffffff816ab4a6>] ? native_safe_halt+0x6/0x10
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff816ab33e>] default_idle+0x1e/0xc0
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81035006>] arch_cpu_idle+0x26/0x30
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff810e7bca>] cpu_startup_entry+0x14a/0x1c0
Jul 21 00:30:09 10-10-99-144 kernel: [<ffffffff81051af6>] start_secondary+0x1b6/0x230
Jul 21 00:30:09 10-10-99-144 kernel: ---[ end trace 1d38ab13aa011722 ]---
在日志中,我们看到了有内核的报错. PS: 该报错之前在/var/log/message 中也有打印,但奈何该套环境错误日志太多,每秒上千条的日志量, mmp 某宇
确认No.9 报文丢失和该报错有关系
3. Error Message Analysis
从上面的log中可以看到以下几个关键点:
* skb_warn_bad_offload
* __skb_gso_segment
* ip_forward
* virtio_net
通过这些关键字进行Google, 我们找到了N多的方案,一一尝试最终确认为网卡的 large-receive-offload
功能导致, 通过 ethtool -K eth0 lro off
解决问题。 — 世界都安静了
Tips:
之前认为报文从eth0 到 flannel.1 之间,中间只剩下了iptables。但是其实在iptables 做完了DNAT之后,将报文交给flannel.1之前,需要kernel 的协议栈的参与,需要协议栈对报文进行解析,然后根据router tables 将报文 forward 到对应的网口上。 这也就是为什么会触发 ip_foward()
调用的原因。 因此 /proc/sys/net/ipv4/ip_forward
也必然等于1。
过程中的坑
1. 坑一
- 主机和虚拟机网络过于复杂,在确认LRO 与该问题有关系后,未能一把将全部物理机的全部网卡都修改到位,导致反复寻找原因
2. 坑二
- 之前测试过程中发现 APP网络访问有问题,但 CLS 网络访问没有问题,将一部分排查方向转移到了两者间的报文路径上
- 但其实是 APP网络用的是1GB网卡,默认LRO是关闭的,而cls网络用的10GB网卡,默认LRO是开启的
3. 坑三
- 在另外一台物理机上进行了模拟,开启LRO之后,确实会导致大包丢包,与K8s环境下的表现一致。 但却没有发现相同的内核报错信息
- 现在怀疑是不同的操作系统版本问题,导致并没有报错日志
4. 坑四
- 在Redhat 官网上找到了同样的内核报错,同样的在 虚拟化环境中跑docker。 点我
- 但Redhat 官方解释是:这个报错只是一个警告,并没有其他恶劣的影响,将在redhat 7.6版本中修复。 wtf,老子丢包啊
相关链接
http://blog.51cto.com/flymanhi/1276331
https://home.regit.org/2014/02/nftables-and-netfilter-logging-framework/
https://access.redhat.com/solutions/654283
https://www.centos.org/forums/viewtopic.php?t=61900
http://lists.openstack.org/pipermail/openstack-operators/2016-May/010524.html
更多推荐
所有评论(0)