On 10/21/2011 10:03 PM, Flavio Leitner wrote: > On Fri, 21 Oct 2011 14:15:12 +0800 > Michael Wang<wang...@linux.vnet.ibm.com> wrote: > >> On 10/19/2011 08:16 PM, Flavio Leitner wrote: >>> On Wed, 19 Oct 2011 12:49:48 +0800 >>> wangyun<wang...@linux.vnet.ibm.com> wrote: >>> >>>> Hi, Flavio >>>> >>>> I am new to join the community, work on e1000e driver currently, >>>> And I found a thing strange in this issue, please check below. >>>> >>>> Thanks, >>>> Michael Wang >>>> >>>> On 10/18/2011 10:42 PM, Flavio Leitner wrote: >>>>> On Mon, 17 Oct 2011 11:48:22 -0700 >>>>> Jesse Brandeburg<jesse.brandeb...@intel.com> wrote: >>>>> >>>>>> On Fri, 14 Oct 2011 10:04:26 -0700 >>>>>> Flavio Leitner<f...@redhat.com> wrote: >>>>>> >>>>>>> Hi, >>>>>>> >>>>>>> I got few reports so far that 82571EB models are having the >>>>>>> "Detected Hardware Unit Hang" issue after upgrading the kernel. >>>>>>> >>>>>>> Further debugging with an instrumented kernel revealed that the >>>>>>> socket buffer time stamp matches with the last time e1000_xmit_frame() >>>>>>> was called. Also that the time stamp of e1000_clean_tx_irq() last run >>>>>>> is prior to the one in socket buffer. >>>>>>> >>>>>>> However, ~1 second later, an interrupt is fired and the old entry >>>>>>> is found. Sometimes, the scheduled print_hang_task dumps the >>>>>>> information _after_ the old entry is sent (shows empty ring), >>>>>>> indicating that the HW TX unit isn't really stuck and apparently >>>>>>> just missed the signal to initiate the transmission. >>>>>>> >>>>>>> Order of events: >>>>>>> (1) skb is pushed down >>>>>>> (2) e1000_xmit_frame() is called >>>>>>> (3) ring is filled with one entry >>>>>>> (4) TDT is updated >>>>>>>> (5) nothing happens for little more than 1 second >>>>>>> (6) interrupt is fired >>>>>>> (7) e1000_clean_tx_irq() is called >>>>>>> (8) finds the entry not ready with an old time stamp, >>>>>>> schedules print_hang_task and stops the TX queue. >>>>>>> (9) print_hang_task runs, dump the info but the old entry is now >>>>>>> sent >>>>>>> (10) apparently the TX queue is back. >>>>>> Flavio, thanks for the detailed info, please be sure to supply us the >>>>>> bugzilla number. >>>>>> >>>>> It was buried in the end of the first email: >>>>> https://bugzilla.redhat.com/show_bug.cgi?id=746272 >>>>> >>>>>> TDH is probably not moving due to the writeback threshold settings in >>>>>> TXDCTL. netperf UDP_RR test is likely a good way to test this. >>>>>> >>>>> Yeah, makes sense. I haven't heard about new events after had removed >>>>> the flag FLAG2_DMA_BURST. Unfortunately, I don't have access to the exact >>>>> same hardware and I haven't reproduced the issue in-house yet with another >>>>> 82571EB. See below about interface statistics from sar.
Currently, if FLAG2_DMA_BURST setted, the device will pre-fetch the tx descriptor only when: 1. the descriptor device cached is lower then 32. 2. The descriptor host prepared is at least one. I don't think this will cause that issue, but another thing it done is to set the device to write-back the processed descriptor only when the amount reach 5(or 4). So may be when the device get a descriptor and processed, but the amount not reached 5, so it don't write-back it, but actually already transmitted. But this will happen only when the transmit suddenly stopped for one second or more, I don't know whether this is the real traffic situation or not. And may be I am wrong about this, but also I think this may be the only reason cause this issue. >>>>> >>>>>> I don't think the sequence is quite what you said. We are going to >>>>>> work with the hardware team to get a sequence that works right, and we >>>>>> should have a fix for you soon. >>>>> Yeah, the sequence might not be exact, but gives us a good idea of >>>>> what could be happening. >>>>> >>>>> There are two events right after another: >>>>> >>>>> Oct 9 05:45:23 kernel: TDH<48> >>>>> Oct 9 05:45:23 kernel: TDT<49> >>>>> Oct 9 05:45:23 kernel: next_to_use<49> >>>>> Oct 9 05:45:23 kernel: next_to_clean<48> >>>>> Oct 9 05:45:23 kernel: buffer_info[next_to_clean]: >>>>> Oct 9 05:45:23 kernel: time_stamp<102338ca6> >>>>> Oct 9 05:45:23 kernel: next_to_watch<48> >>>>> Oct 9 05:45:23 kernel: jiffies<102338dc1> >>>>> Oct 9 05:45:23 kernel: next_to_watch.status<0> >>>>> Oct 9 05:45:23 kernel: MAC Status<80383> >>>>> Oct 9 05:45:23 kernel: PHY Status<792d> >>>>> Oct 9 05:45:23 kernel: PHY 1000BASE-T Status<3800> >>>>> Oct 9 05:45:23 kernel: PHY Extended Status<3000> >>>>> Oct 9 05:45:23 kernel: PCI Status<10> >>>>> Oct 9 05:51:54 kernel: e1000e 0000:22:00.1: eth7: Detected Hardware >>>>> Unit Hang: >>>>> Oct 9 05:51:54 kernel: TDH<55> >>>>> Oct 9 05:51:54 kernel: TDT<56> >>>>> Oct 9 05:51:54 kernel: next_to_use<56> >>>>> Oct 9 05:51:54 kernel: next_to_clean<55> >>>>> Oct 9 05:51:54 kernel: buffer_info[next_to_clean]: >>>>> Oct 9 05:51:54 kernel: time_stamp<102350986> >>>>> Oct 9 05:51:54 kernel: next_to_watch<55> >>>>> Oct 9 05:51:54 kernel: jiffies<102350b07> >>>>> Oct 9 05:51:54 kernel: next_to_watch.status<0> >>>>> Oct 9 05:51:54 kernel: MAC Status<80383> >>>>> Oct 9 05:51:54 kernel: PHY Status<792d> >>>>> Oct 9 05:51:54 kernel: PHY 1000BASE-T Status<3800> >>>>> Oct 9 05:51:54 kernel: PHY Extended Status<3000> >>>>> Oct 9 05:51:54 kernel: PCI Status<10> >>>>> >>>> I see the judgement of hang is: >>>> >>>> time_after(jiffies, tx_ring->buffer_info[i].time_stamp + >>>> (adapter->tx_timeout_factor * HZ)) >>>> >>>> which means the hang happened when current jiffies minus buffer's time >>>> stamp is over >>>> (adapter->tx_timeout_factor * HZ). >>>> >>>> And I see the tx_timeout_factor will at least be 1, so on x86 the >>>> (jiffies-time_stamp) should >>>> over 1000, but here looks only around 300. >>>> >>>> Could you please check the HZ number of your platform? >>>> >>> sure, adapter->tx_timeout_factor * HZ = 0xfa/250d >>> That data came from a customer using kernel-xen, so HZ is 250. >>> >>> Here is the debugging patch used: >>> http://people.redhat.com/~fleitner/linux-kernel-test.patch >>> >>> The idea was to capture all the relevant values at the time >>> of the problem. (The print_hang_task is scheduled and sometimes >>> it shows timestamp=0, TDH=TDT because the packet is already sent) >>> >>> This is the full output with debugging patch applied: >>> Oct 11 02:03:52 kernel: e1000e 0000:22:00.1: eth7: Detected Hardware Unit >>> Hang: >>> Oct 11 02:03:52 kernel: TDH<25> >>> Oct 11 02:03:52 kernel: TDT<26> >>> Oct 11 02:03:52 kernel: next_to_use<26> >>> Oct 11 02:03:52 kernel: next_to_clean<25> >>> Oct 11 02:03:52 kernel: buffer_info[next_to_clean]: >>> Oct 11 02:03:52 kernel: time_stamp<100b2aa22> >>> Oct 11 02:03:52 kernel: next_to_watch<25> >>> Oct 11 02:03:52 kernel: jiffies<100b2ab25> >>> Oct 11 02:03:52 kernel: next_to_watch.status<0> >>> Oct 11 02:03:52 kernel: stored_i =<25> >>> Oct 11 02:03:52 kernel: stored_first =<25> >>> Oct 11 02:03:52 kernel: stamp =<100b2aa22> >>> Oct 11 02:03:52 kernel: factor =<fa> >>> Oct 11 02:03:52 kernel: last_clean =<100b2aa1a> >>> Oct 11 02:03:52 kernel: last_tx =<100b2aa22> >>> Oct 11 02:03:52 kernel: count =<0>/<100> >> The tx_ring->count seems not the default value which should be 256, >> could you please check if you have change this number to 100? >> > If you look at the debugging patch mentioned above, you will see > that it prints in hexa, so that is actually 0x100 which is the 256d > you are looking for. This is my silly mistake, I am sorry for that. > To be clear, the driver reproducing the issue is the one shipped > in 2.6.18-274.el5 (Red Hat Enterprise Linux 5 Update 7) with no > other patches. In order to get more details at the time of the > event, we had applied the patch mentioned above, nothing else. > > thanks, > fbl So have you try to use the Red Hat 6, is this problem still exist? Regards, Michael Wang ------------------------------------------------------------------------------ The demand for IT networking professionals continues to grow, and the demand for specialized networking skills is growing even more rapidly. Take a complimentary Learning@Cisco Self-Assessment and learn about Cisco certifications, training, and career opportunities. http://p.sf.net/sfu/cisco-dev2dev _______________________________________________ E1000-devel mailing list E1000-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/e1000-devel To learn more about Intel® Ethernet, visit http://communities.intel.com/community/wired
