《动手测试单机百万连接》实验记录（二）

xing393939 的个人博客 / 0 / 0 / 创建于 1年前 / 更新于 1年前

上篇文章，虽然已经成功达到了实验的目标，但是碰到的两个问题，都是在网上搜到的答案，或者说是靠猜测和尝试解决的。能不能凭借内核的一些知识来解决呢？

现在重新看问题一，假设内核并没有任何错误信息，如何定位到具体原因呢？还是运行 bpftrace kfree_skb.bt，kfree_skb.bt 的源码如下：

kprobe:kfree_skb
{
        $skb = (struct sk_buff*) arg0;
        $ip_header = ((struct iphdr *) ($skb->head + $skb->network_header));
        // 这里只捕获 daddr 是 192.168.2.120 的包
        if ($ip_header->protocol == IPPROTO_TCP && $ip_header->daddr == 0x7802a8c0)
        {
                $tcp_header= ((struct tcphdr *) ($skb->head + $skb->network_header + ($ip_header->ihl << 2)));
                $sport = $tcp_header->source;
                $dport = $tcp_header->dest;
                $dport = ($dport >> 8) | (($dport << 8) & 0xff00);
                $sport = ($sport >> 8) | (($sport << 8) & 0xff00);
                // 这里只捕获 dport 是 8100 的包
                if ($dport == 8100) {
                        @[kstack(11)] = count();
                        time("%H:%M:%S ");
                        printf("%s:%d > %s:%d\n", ntop($ip_header->saddr), $sport, ntop($ip_header->daddr), $dport);
                }
        }
}

得到的结果如下

@[
    kfree_skb_reason+1
    nf_hook_slow_list+113
    ip_sublist_rcv+505
    ip_list_rcv+249
    __netif_receive_skb_list_core+553
    netif_receive_skb_list_internal+403
    napi_complete_done+122
    e1000e_poll+218
    __napi_poll+48
    net_rx_action+389
    __softirqentry_text_start+213
]: 42

查看nf_hook_slow_list的源码，它调用了nf_hook_slow，接下来还是用./funcgraph -a ip_sublist_rcv查看nf_hook_slow_list的下游调用链，结果抓取到了很多结果，究竟哪一个才是丢包时候的调用链呢？ftrace只支持进程id的过滤，而收包过程是软中断时内核线程来完成的，而且提前并不能知道。

于是我查询ftrace的手册，看到可以调用内核函数trace_printk往ftrace的结果中插入自定义的comment，而ebpf的辅助函数bpf_trace_printk正好可以做到这一点。我们可以利用这一点往调用nf_hook_slow（并且是处理丢包的那个skb的调用链）的地方插入comment，运行bpftrace nf_hook_slow.bt（注意bpftrace的版本>=0.17），nf_hook_slow.bt的代码如下：

kprobe:nf_hook_slow
{
        $skb = (struct sk_buff*) arg1;
        $ip_header = ((struct iphdr *) ($skb->head + $skb->network_header));
        if ($ip_header->protocol == IPPROTO_TCP && $ip_header->daddr == 0x7802a8c0)
        {
                $tcp_header= ((struct tcphdr *) ($skb->head + $skb->network_header + ($ip_header->ihl << 2)));
                $sport = $tcp_header->source;
                $dport = $tcp_header->dest;
                $dport = ($dport >> 8) | (($dport << 8) & 0xff00);
                $sport = ($sport >> 8) | (($sport << 8) & 0xff00);
                if ($dport == 8100) {
                        time("%H:%M:%S ");
                        printf("%s:%d > %s:%d\n", ntop($ip_header->saddr), $sport, ntop($ip_header->daddr), $dport);
                        debugf("%d > %d", $sport, $dport);
                }
        }
}
kprobe:kfree_skb
{
        $skb = (struct sk_buff*) arg0;
        $ip_header = ((struct iphdr *) ($skb->head + $skb->network_header));
        // 这里只捕获 daddr 是 192.168.2.120 的包
        if ($ip_header->protocol == IPPROTO_TCP && $ip_header->daddr == 0x7802a8c0)
        {
                $tcp_header= ((struct tcphdr *) ($skb->head + $skb->network_header + ($ip_header->ihl << 2)));
                $sport = $tcp_header->source;
                $dport = $tcp_header->dest;
                $dport = ($dport >> 8) | (($dport << 8) & 0xff00);
                $sport = ($sport >> 8) | (($sport << 8) & 0xff00);
                // 这里只捕获 dport 是 8100 的包
                if ($dport == 8100) {
                        time("%H:%M:%S ");
                        printf("%s:%d > %s:%d\n", ntop($ip_header->saddr), $sport, ntop($ip_header->daddr), $dport);
                }
        }
}

再次运行./funcgraph -a ip_sublist_rcv可以看到在丢包的调用链nf_hook_slow会出现一行comment，类似/* bpf_trace_printk: 48876 > 8100 */，这样我们就可以精准的定位到丢包时刻的调用链了，接下来就是根据调用链来看源码了，先贴一下funcgraph抓到的调用链结果：

274972.252065 |   5)   ksoftir-47   |               |  ip_sublist_rcv() {
274972.252066 |   5)   ksoftir-47   |   0.961 us    |    __rcu_read_lock();
274972.252068 |   5)   ksoftir-47   |               |    nf_hook_slow_list() {
274972.252070 |   5)   ksoftir-47   |               |      nf_hook_slow() {
274972.252071 |   5)   ksoftir-47   |               |        kprobe_ftrace_handler() {
274972.252424 |   5)   ksoftir-47   |               |          /* bpf_trace_printk: 48876 > 8100 */
274972.252434 |   5)   ksoftir-47   | ! 363.954 us  |        }
274972.252436 |   5)   ksoftir-47   |   1.257 us    |        ip_sabotage_in [br_netfilter]();
274972.252439 |   5)   ksoftir-47   |   1.213 us    |        ipv4_conntrack_defrag [nf_defrag_ipv4]();
274972.252441 |   5)   ksoftir-47   |               |        ipv4_conntrack_in [nf_conntrack]() {
274972.252442 |   5)   ksoftir-47   |               |          nf_conntrack_in [nf_conntrack]() {
274972.252443 |   5)   ksoftir-47   |   1.046 us    |            get_l4proto [nf_conntrack]();
274972.252445 |   5)   ksoftir-47   |               |            resolve_normal_ct [nf_conntrack]() {
274972.252446 |   5)   ksoftir-47   |               |              nf_ct_get_tuple [nf_conntrack]() {
274972.252448 |   5)   ksoftir-47   |   0.996 us    |                nf_ct_get_tuple_ports.constprop.0 [nf_conntrack]();
274972.252449 |   5)   ksoftir-47   |   2.966 us    |              }
274972.252450 |   5)   ksoftir-47   |   1.272 us    |              hash_conntrack_raw [nf_conntrack]();
274972.252453 |   5)   ksoftir-47   |               |              __nf_conntrack_find_get [nf_conntrack]() {
274972.252454 |   5)   ksoftir-47   |   0.987 us    |                __rcu_read_lock();
274972.252457 |   5)   ksoftir-47   |   1.017 us    |                __rcu_read_unlock();
274972.252459 |   5)   ksoftir-47   |   6.287 us    |              }
274972.252460 |   5)   ksoftir-47   |               |              init_conntrack.constprop.0 [nf_conntrack]() {
274972.252461 |   5)   ksoftir-47   |   1.261 us    |                nf_ct_invert_tuple [nf_conntrack]();
274972.252463 |   5)   ksoftir-47   |               |                __nf_conntrack_alloc [nf_conntrack]() {
274972.252464 |   5)   ksoftir-47   |   0.978 us    |                  __rcu_read_lock();
274972.252467 |   5)   ksoftir-47   |   1.002 us    |                  __rcu_read_unlock();
274972.252468 |   5)   ksoftir-47   |               |                  early_drop [nf_conntrack]() {
274972.252469 |   5)   ksoftir-47   |   0.965 us    |                    __rcu_read_lock();
274972.252472 |   5)   ksoftir-47   |   1.049 us    |                    __rcu_read_unlock();
274972.252474 |   5)   ksoftir-47   |   1.132 us    |                    __rcu_read_lock();
274972.252476 |   5)   ksoftir-47   |   0.994 us    |                    __rcu_read_unlock();
274972.252478 |   5)   ksoftir-47   |   0.987 us    |                    __rcu_read_lock();
274972.252481 |   5)   ksoftir-47   |   1.202 us    |                    __rcu_read_unlock();
274972.252483 |   5)   ksoftir-47   |   1.311 us    |                    __rcu_read_lock();
274972.252486 |   5)   ksoftir-47   |   0.977 us    |                    __rcu_read_unlock();
274972.252488 |   5)   ksoftir-47   |   1.038 us    |                    __rcu_read_lock();
274972.252490 |   5)   ksoftir-47   |   1.436 us    |                    __rcu_read_unlock();
274972.252493 |   5)   ksoftir-47   |   1.062 us    |                    __rcu_read_lock();
274972.252495 |   5)   ksoftir-47   |   0.840 us    |                    __rcu_read_unlock();
274972.252497 |   5)   ksoftir-47   |   0.963 us    |                    __rcu_read_lock();
274972.252499 |   5)   ksoftir-47   |   0.949 us    |                    __rcu_read_unlock();
274972.252500 |   5)   ksoftir-47   |   1.009 us    |                    __rcu_read_lock();
274972.252503 |   5)   ksoftir-47   |   1.009 us    |                    __rcu_read_unlock();
274972.252504 |   5)   ksoftir-47   | + 36.030 us   |                  }
274972.252506 |   5)   ksoftir-47   |               |                  net_ratelimit() {
274972.252507 |   5)   ksoftir-47   |   1.163 us    |                    _raw_spin_trylock();
274972.252510 |   5)   ksoftir-47   |   1.137 us    |                    _raw_spin_unlock_irqrestore();
274972.252512 |   5)   ksoftir-47   |   6.035 us    |                  }
274972.252513 |   5)   ksoftir-47   |               |                  _printk() {
274972.252624 |   5)   ksoftir-47   | ! 111.979 us  |                  }
274972.252625 |   5)   ksoftir-47   | ! 162.001 us  |                }
274972.252626 |   5)   ksoftir-47   | ! 166.517 us  |              }
274972.252627 |   5)   ksoftir-47   | ! 181.756 us  |            } /* resolve_normal_ct [nf_conntrack] */
274972.252628 |   5)   ksoftir-47   | ! 186.205 us  |          }
274972.252629 |   5)   ksoftir-47   | ! 188.247 us  |        }
274972.252630 |   5)   ksoftir-47   |               |        kfree_skb_reason() {
274972.252632 |   5)   ksoftir-47   |               |          kprobe_ftrace_handler() {
274972.253227 |   5)   ksoftir-47   | ! 595.718 us  |          }
274972.253228 |   5)   ksoftir-47   |   1.375 us    |          skb_release_head_state();
274972.253231 |   5)   ksoftir-47   |               |          skb_release_data() {
274972.253232 |   5)   ksoftir-47   |               |            skb_free_head() {
274972.253233 |   5)   ksoftir-47   |   1.419 us    |              kfree();
274972.253235 |   5)   ksoftir-47   |   3.270 us    |            }
274972.253236 |   5)   ksoftir-47   |   5.350 us    |          }
274972.253237 |   5)   ksoftir-47   |               |          kfree_skbmem() {
274972.253238 |   5)   ksoftir-47   |               |            kmem_cache_free() {
274972.253240 |   5)   ksoftir-47   |   1.368 us    |              __slab_free();
274972.253242 |   5)   ksoftir-47   |   3.944 us    |            }
274972.253243 |   5)   ksoftir-47   |   5.910 us    |          }
274972.253244 |   5)   ksoftir-47   | ! 613.834 us  |        }
274972.253245 |   5)   ksoftir-47   | # 1175.182 us |      }
274972.253245 |   5)   ksoftir-47   | # 1177.527 us |    }
274972.253247 |   5)   ksoftir-47   |   1.182 us    |    __rcu_read_unlock();
274972.253249 |   5)   ksoftir-47   |   1.148 us    |    ip_sublist_rcv_finish();
274972.253251 |   5)   ksoftir-47   | # 1186.144 us |  }

最终可以看到是在调用__nf_conntrack_alloc时出了问题，源码如下：

static struct nf_conn *
__nf_conntrack_alloc(struct net *net,
             const struct nf_conntrack_zone *zone,
             const struct nf_conntrack_tuple *orig,
             const struct nf_conntrack_tuple *repl,
             gfp_t gfp, u32 hash)
{
    struct nf_conntrack_net *cnet = nf_ct_pernet(net);
    unsigned int ct_count;
    struct nf_conn *ct;
    if (nf_conntrack_max && unlikely(ct_count > nf_conntrack_max)) {
        if (!early_drop(net, hash)) {
            if (!conntrack_gc_work.early_drop)
                conntrack_gc_work.early_drop = true;
            atomic_dec(&cnet->count);
            net_warn_ratelimited("nf_conntrack: table full, dropping packet\n");
            return ERR_PTR(-ENOMEM);
        }
    }

然后可以定位到是内核的nf_conntrack_max配置小了，至此，问题一已经定位到了，修改内核即可解决。

本作品采用《CC 协议》，转载必须注明作者和本文链接

xing393939

278 声望

暂无个人描述~

0 人点赞

讨论数量: 0

(=￣ω￣=)··· 暂无内容！

讨论应以学习和精进为目的。请勿发布不友善或者负能量的内容，与人为善，比聪明更重要！

帮助

《动手测试单机百万连接》实验记录（二）

社区赞助商

关于 LearnKu

资源推荐

服务提供商

其他信息

《动手测试单机百万连接》实验记录（二）

社区赞助商

关于 LearnKu

资源推荐

服务提供商

其他信息

请登录