网卡驱动死机调试经验案例

一、现象执行iperf打流后不管是udp打流还是tcp打流命令行没有响应无法敲入任何字符也没有回显但一段时间后串口有打印查看代码后发现是EMAC的DMA中断里打印的打印的内容如下[13:39:23:743]37.4320Mbps![13:39:46:157]37.4490Mbps![13:40:08:589]37.4490Mbps![14:26:59:361]intr0x86980c0[14:27:02:590]intr0x8688080[14:27:03:390]intr0x8688080[14:27:11:837]intr0x8688080[14:27:15:579]intr0x8688080[14:27:16:331]intr0x8688080[14:27:28:217]intr0x8688080[14:27:30:680]intr0x8688080[14:27:35:575]intr0x8688080[14:27:42:598]intr0x8688080[14:27:45:103]intr0x8688080………二、问题排查首先找到打印对应的中断函数如下所示irqreturn_tvmc_interrupt(intirqno,void*param){structemac_device*edev(structemac_device*)param;structeth_device*ethedev-parent;intintsemac_read_reg((u32*)(edev-dma_base),DmaStatus);intenemac_read_reg((u32*)(edev-dma_base),DmaInterrupt);emac_write_reg((u32*)(edev-dma_base),DmaStatus,ints);emac_write_reg((u32*)(edev-dma_base),DmaInterrupt,0);if(intsDmaIntTxCompleted){rt_event_send(emac_event,EMAC_EVENT_TX_COMPLETE);}if(intsDmaIntRxCompleted){eth_device_ready(eth);}if(intsDmaIntAbnormal){EMAC_PRINTF(VIM_EMAC_DEBUG,intr 0x%x\n,ints);}emac_write_reg((u32*)(edev-dma_base),DmaInterrupt,en);return0;}可以看到是发生了异常的DMA中断打印的第一个异常的DmaStatus寄存器值是0x86980c0对照寄存器手册发现网卡接收DMA块被用完了如下所示。在注意到死机时的串口打印时间异常日志与正常iperf打流的最后一条日志相差了46分钟因此可以推测是这段时间内网卡的接收函数没有执行导致网卡DMA接收buffer消耗殆尽从串口不能输入也侧面印证了这一点因此可以推测程序可能是死在某个循环里了可能是比网卡接收线程、shell线程优先级更高的线程或是卡在某个中断里出不来了。为了验证是否卡在线程里有很多种办法例如在rtt线程调度器里加打印看是从哪个线程切到哪个线程最后卡住了但是这样打印会非常多所以简单的办法就是提高shell线程的优先级去验证实测把shell现场优先级提高最高仍然会死机因此可以推测大概率是卡死在中断里了。这里直接用JlinkGDB调试的方式去验证结果每次全速运行暂停时程序总停在中断里中断入口函数如下所示其中cnt是调试加的当一直卡在中断里出不来时会打印对应的中断号果然这个中断号和EMAC的中断号是一致的。voidgic_handle_irq(irq_regs_t*regs){uint32_tirqstat,irqnr;staticuint32_tcnt0;do{irqstatreadl(GIC_CPU_AIAR_REG);irqnrirqstatGICC_IAR_INT_ID_MASK;if(likely(irqnr15irqnr1020)){writel(irqstat,GIC_CPU_AEOI_REG);isb();handle_domain_irq(NULL,irqnr,regs);if(cnt1000){cnt0;__log(int %d,irqnr);}continue;}if(irqnr16){writel(irqstat,GIC_CPU_AEOI_REG);writel(irqstat,GIC_CPU_DEACTIVATE);#ifdefRT_USING_SMP/* ¦* Ensure any shared data written by the CPU sending ¦* the IPI is read after weve read the ACK register ¦* on the GIC. ¦* ¦* Pairs with the write barrier in gic_raise_softirq ¦*/smp_rmb();handle_IPI(irqnr,regs);#endifcontinue;}cnt0;break;}while(1);}因此可以推测是EMAC的某个中断没清除导致反复进入EMAC的中断细查发现正常DmaStatus寄存器的bit27是0每次卡住时这个位都是1这个bit位的描述如下查看代码和寄存器手册发现EMAC不止DmaStatus这个状态寄存器还有个GmacInterruptStatus于是异常时将这个寄存器的值也打印出来发现是0x50对应的寄存器描述如下好吧这个寄存器描述讲了个寂寞于是看linux sdk的代码发现有个函数叫vmc_emac_disable_mmc_tx_interrupt好像和这个有点关系再看这个函数操作的寄存器实际是屏蔽了和发送统计相关的功能这个寄存器有25个bit位刚好对应25种发送数据统计。在linux sdk里所有的mask都置1了相当于关闭了所有的发送统计。虽然没有功能说明什么时候会产生中断但翻过头看串口日志发现每次都是打印了19次iperf结果后卡住怀疑应该是发送的数据量达到了某个数比如超过32位的数据量时会产生对应的中断而这个中断没有去清除。三、问题修复参考linux sdk的做法将发送和接收的统计功能关闭问题不再复现。