概念理解:中断(Interrupt)
中断是系统用来响应硬件设备请求的一种机制,它会打断进程的正常调度和执行,然后调用内核中的中断处理程序来响应设备的请求。
中断其实是一种异步的事件处理机制,可以提高系统的并发处理能力。
为了减少对正常进程运行调度的影响,中断处理程序就需要尽可能快地运行。如果中断要处理的事情很多,中断服务程序就有可能要运行很长时间。特别是中断处理程序在响应中断时,还会临时关闭中断。这就会导致上次中断处理完成之前,其他中断都不能响应,也就是说中断有可能会丢失。
为了解决中断处理程序执行过长和中断丢失的问题,Linux 将中断处理过程分成了两个阶段,也就是上半部和下半部:
上半部:用来快速处理中断,它在中断禁止模式下运行,主要处理跟硬件紧密相关的或时间敏感的工作;特点是快速执行;上半部会打断 CPU 正在执行的任务,然后立即执行中断处理程序。
下半部:用来延迟处理上半部未完成的工作,通常以内核线程的方式运行;特点是延迟执行;
以网卡收发数据为列:
1)网卡接收到数据包后,会通过硬件中断的方式,通知内核有新的数据到了,内核就应该调用中断处理程序来响应它
2)对上半部来说,快速处理,把网卡的数据读到内存中,然后更新硬件寄存器的状态(表示数据读取完成),最后再发送软中断信号,通知下半部做进一步的处理
3)下半部被软中断信号唤醒后,需要从内存中找到网络数据,再按照网络协议栈,对数据进行逐层解析和处理,直到把它送给应用程序
硬中断(Hardware interrupts)
上半部是发生硬件中断时调用,它不是软中断。
软中断(Software interrupts)
下半部则是软中断,下半部(软中断)以内核线程的方式执行,并且每个 CPU 都对应一个软中断内核线程,名字为 “ksoftirqd/<CPU N>”,比如说,0 号 CPU 对应的软中断内核线程的名字就是 ksoftirqd/0:
# ps aux | grep softirq root 9 0.0 0.0 0 0 ? S Jul05 0:37 [ksoftirqd/0] root 17 0.0 0.0 0 0 ? S Jul05 0:35 [ksoftirqd/1] root 22 0.0 0.0 0 0 ? S Jul05 0:48 [ksoftirqd/2] root 27 0.0 0.0 0 0 ? S Jul05 0:29 [ksoftirqd/3] // 这些线程的名字外面都有中括号,这说明 ps 无法获取它们的命令行参数
一些内核自定义的事件也属于软中断,比如内核调度和 RCU 锁(Read-Copy Update 的缩写,RCU 是 Linux 内核中最常用的锁之一)等。
tasklet
tasklet 是特殊软中断:
1)同个时刻,每个 CPU 上仅能存在单个 tasklet 进程;
2)多个 tasklet 仅能在不同的 CPU 上执行;
3)常规的软中断,在同个时刻中能在不同 CPU 上并行执行;
TASKLET 在不同 CPU 上的分布并不均匀。TASKLET 是最常用的软中断实现机制,每个 TASKLET 只运行一次就会结束 ,并且只在调用者(调用它的函数)所在的 CPU 上运行。因此,使用 TASKLET 特别简便,当然也会存在一些问题,比如说由于只在一个 CPU 上运行导致的调度不均衡,再比如因为不能在多个 CPU 上并行运行带来了性能限制。
使用说明
内核很多地方使用 tasklet 中断。
DECLARE_TASKLET_DISABLED(hil_mics_tasklet, hil_mics_process, 0); tasklet_schedule(&hil_mics_tasklet); // 该代码定义 tasklet 中断,其将调用 hil_mics_tasklet 函数: // 1)tasklet_schedule() 将其插入 tasklet 链表,然后触发 tasklet 中断; // 2)内核将根据情况确定何时执行在 tasklet 链表中的函数。
查看软/硬中断的运行情况
/proc/interrupts,硬中断
# cat /proc/interrupts CPU0 CPU1 CPU2 CPU3 0: 34 0 0 0 IR-IO-APIC 2-edge timer 1: 771129 0 0 11 IR-IO-APIC 1-edge i8042 8: 0 1 0 0 IR-IO-APIC 8-edge rtc0 9: 1223077 586 0 0 IR-IO-APIC 9-fasteoi acpi 12: 89 0 191 0 IR-IO-APIC 12-edge i8042 16: 866 37 0 0 IR-IO-APIC 16-fasteoi ehci_hcd:usb1 18: 1185157 0 242 0 IR-IO-APIC 18-fasteoi i801_smbus 23: 1045 0 0 0 IR-IO-APIC 23-fasteoi ehci_hcd:usb4 24: 0 0 0 0 DMAR-MSI 0-edge dmar0 25: 0 0 0 0 DMAR-MSI 1-edge dmar1 26: 3892 0 0 2400 IR-PCI-MSI 1572864-edge rtsx_pci 27: 0 499438 0 0 IR-PCI-MSI 327680-edge xhci_hcd 28: 0 0 0 0 IR-PCI-MSI 49152-edge snd_hda_intel:card0 29: 115526240 95216 0 0 IR-PCI-MSI 512000-edge ahci[0000:00:1f.2] 30: 77371700 0 2643 0 IR-PCI-MSI 32768-edge i915 31: 1720 0 0 51 IR-PCI-MSI 524288-edge nvkm 32: 0 0 42 0 IR-PCI-MSI 360448-edge mei_me 33: 296681 0 24 0 dummy 44 rmi4_smbus 34: 0 0 0 25619 IR-PCI-MSI 442368-edge snd_hda_intel:card1 35: 0 0 1485853 0 IR-PCI-MSI 409600-edge enp0s25 36: 0 0 0 0 rmi4 0 rmi4-00.fn34 37: 3844818 0 0 1891 IR-PCI-MSI 2097152-edge iwlwifi 38: 0 0 0 0 rmi4 1 rmi4-00.fn01 39: 0 0 0 3575 rmi4 2 rmi4-00.fn03 40: 0 0 0 293511 rmi4 3 rmi4-00.fn11 41: 0 0 0 0 rmi4 4 rmi4-00.fn11 42: 0 0 0 164 rmi4 6 rmi4-00.fn30 NMI: 667290 701762 689673 695548 Non-maskable interrupts LOC: 1791387315 1542744110 1788973003 1546345222 Local timer interrupts SPU: 0 0 0 0 Spurious interrupts PMI: 667290 701762 689673 695548 Performance monitoring interrupts IWI: 9750032 187135 41911 43536 IRQ work interrupts RTR: 0 0 0 0 APIC ICR read retries RES: 618925825 653811229 617163661 642433584 Rescheduling interrupts CAL: 104747233 98810176 104768432 98818573 Function call interrupts TLB: 29430095 29200153 29608591 29095121 TLB shootdowns TRM: 456 456 456 456 Thermal event interrupts THR: 0 0 0 0 Threshold APIC interrupts DFR: 0 0 0 0 Deferred Error APIC interrupts MCE: 0 0 0 0 Machine check exceptions MCP: 6362 6350 6350 6350 Machine check polls HYP: 0 0 0 0 Hypervisor callback interrupts HRE: 0 0 0 0 Hyper-V reenlightenment interrupts HVS: 0 0 0 0 Hyper-V stimer0 interrupts ERR: 0 MIS: 0 PIN: 0 0 0 0 Posted-interrupt notification event NPI: 0 0 0 0 Nested posted-interrupt event PIW: 0 0 0 0 Posted-interrupt wakeup event
/proc/softirqs,软中断
# cat /proc/softirqs CPU0 CPU1 CPU2 CPU3 CPU4 CPU5 CPU6 CPU7 HI: 136 369 132 134 0 0 0 0 TIMER: 405492591 396842738 401762899 396134491 0 0 0 0 NET_TX: 713323 117120 2591841 146253 0 0 0 0 NET_RX: 3349499 2976923 46381531 3014991 0 0 0 0 BLOCK: 52 0 6 11 0 0 0 0 IRQ_POLL: 52 0 6 11 0 0 0 0 TASKLET: 686605 2472 1679347 1611 0 0 0 0 SCHED: 448291677 450782129 444375299 445882886 0 0 0 0 HRTIMER: 180 13 284974 24 0 0 0 0 RCU: 170353155 184421988 173196312 171734376 0 0 0 0
在查看 /proc/softirqs 文件内容时,要特别注意以下:
1)要注意软中断的类型,也就是第一列。比如 NET_RX 表示网络接收中断,而 NET_TX 表示网络发送中断;
2)要注意同一种软中断在不同 CPU 上的分布情况。正常情况,同种中断在不同 CPU 上的累积次数应该相近;
问题排查:软中断 CPU 使用率过高
当软中断事件的频率过高时,内核线程也会因为 CPU 使用率过高而导致软中断处理不及时,进而引发网络收发延迟、调度缓慢等性能问题。
第一步、初始化环境,创造负载
// 在 a 主机执行: # docker run -itd --name=nginx-softirqs -p 30128:80 nginx // 在 b 主机执行: # hping3 -S -p 30128 -i u100 10.10.50.166 // -S参数表示设置TCP协议的SYN(同步序列号),-p表示目的端口为80,-i u100表示每隔100微秒发送一个网络帧 // 如果在实践过程中现象不明显,可以尝试把 100 调小,比如调成 10 甚至 1 // 这时候会发现,在 a 主机终端操作,响应特别慢 // 这里是使用 hping3 模拟 SYN FLOOD 攻击
第二步、问题排查,观察资源
// 使用 top 命令观察进程 # top top - 19:51:59 up 4:55, 2 users, load average: 0.85, 0.40, 0.23 Tasks: 173 total, 3 running, 170 sleeping, 0 stopped, 0 zombie %Cpu(s): 2.2 us, 2.0 sy, 0.0 ni, 46.3 id, 0.0 wa, 0.0 hi, 49.5 si, 0.0 st MiB Mem : 6813.8 total, 538.3 free, 1182.2 used, 5093.3 buff/cache MiB Swap: 0.0 total, 0.0 free, 0.0 used. 5327.3 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 14 root 20 0 0.0m 0.0m 0.0m R 94.4 0.0 1:34.30 [ksoftirqd/1] 9 root 20 0 0.0m 0.0m 0.0m R 2.6 0.0 0:44.20 [rcu_sched] 16131 systemd+ 20 0 1152.5m 269.7m 13.0m S 2.0 4.0 12:00.75 mongod --smallf // 第一行,系统 load average 并不高,没有过大负载 // 第二行,系统进程数量也算正常,没有过高 // 第三行,整体上还算正常,但是 si 软中断比较高 // 进程列表 ksoftirqd/1 的 CPU 使用较高 // 因此,问题的焦点在于系统的软中断较多,我们需要观察系统内软中断的变化 # watch -d cat /proc/softirqs Every 2.0s: cat /proc/softirqs Wed Jul 29 20:00:17 2020 CPU0 CPU1 HI: 0 0 TIMER: 3476024 3983214 NET_TX: 4052 531 NET_RX: 1189072 7407551 BLOCK: 559537 580 BLOCK_IOPOLL: 0 0 TASKLET: 2800 9891 SCHED: 1724200 1709649 HRTIMER: 0 0 RCU: 1883717 2259696 // TIMER(定时中断)、NET_RX(网络接收)、SCHED(内核调度)、RCU(RCU 锁)等这几个软中断都在不停变化 // TIMER SCHED RCU 有变化是正常的,但是 NET_RX 变化不正常,两个 CPU 差距非常大 // 因此我们尝试从网络方面入手进行分析,使用 sar 命令 # sar -n DEV 1 // -n DEV 表示显示网络收发的报告,间隔1秒输出一组数据 08:19:12 IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s 08:19:13 vethd795404 7281.16 14549.28 412.41 767.25 0.00 0.00 0.00 08:19:13 ens32 14678.26 7401.45 867.14 455.93 0.00 0.00 0.00 08:19:13 vethb2c1b4e 7.25 8.70 0.41 0.55 0.00 0.00 0.00 08:19:13 lo 8.70 8.70 0.66 0.66 0.00 0.00 0.00 08:19:13 vethdaea328 88.41 86.96 23.40 10.53 0.00 0.00 0.00 08:19:13 docker0 7369.57 14646.38 335.05 778.40 0.00 0.00 0.00 ...(我们删除了数据全为 0.00 的行) // 流量经过网卡 ens32 经过内部转发到了 docker0 // 从 ens32 上可以看出,接受的数据包较多(14678.26),但是接收的字节书却很少(867.14) // echo $((867.14 * 1024 / 14678.26)) => 60,每个数据包只有 60 字节 // 那么问题可能是由于大量较小数据包,导致系统频繁软中断 // 使用 tcpdump 进行抓包 # tcpdmp -i ens32 -n tcp port 30128 08:36:55.349947 IP 10.10.12.122.14723 > 10.10.50.166.30128: Flags [R], seq 1496244438, win 0, length 0 08:36:55.350009 IP 10.10.50.166.30128 > 10.10.12.122.14726: Flags [S.], seq 367244068, ack 493131568, win 29200, options [mss 1460], length 0 08:36:55.350026 IP 10.10.50.166.30128 > 10.10.12.122.14727: Flags [S.], seq 3989225294, ack 986933336, win 29200, options [mss 1460], length 0 08:36:55.350152 IP 10.10.12.122.14728 > 10.10.50.166.30128: Flags [S], seq 236237122, win 512, length 0 08:36:55.350182 IP 10.10.12.122.14724 > 10.10.50.166.30128: Flags [R], seq 2006016495, win 0, length 0 08:36:55.350190 IP 10.10.12.122.14725 > 10.10.50.166.30128: Flags [R], seq 879500927, win 0, length 0 08:36:55.350197 IP 10.10.12.122.14729 > 10.10.50.166.30128: Flags [S], seq 1481866473, win 512, length 0 // Flags [S] 则表示这是一个 SYN 包 // tcpdump 输出一直在重复“某种模式“ // 结合 sar 输出,我们可以断定这是 syn flood 工具 // top => ksoftirqs => /proc/softirqs => NET_RX => sar => eth0 => tcpdump => syn flood // 关于 syn flood 解决思路这里不再展开
参考文献