[dpdk-dev] phantom old packets received in new mbuf

[Helmut Sim]

Just to update, root cause is found...
the problem is not at the dpdk rx side but at the transmit side (using
sendto app).

when transmitting through NICs models 82575 or 82576 (sendto app), the
receiver reads it well using the DPDK rx program.
however when using NIC 82541gi as transmitter (sendto app), the DPDK
receiver reads it wrong.

I puted a first sniffer on the transmitting NIC and a second sniffer on the
cable between the two NICs and found out that: while the first sniffer
reads correct sequence of packets, the second sniffer reads wrong sequence
(in fact an old packet replaces a new packet...).

All of my six 82541gi NICs behaves at the same way... :(
maybe it is a driver issue (will look for it latter).

Thank for your advices and assistance,




On Wed, Jul 16, 2014 at 4:22 PM, Helmut Sim <simhelmut at gmail.com> wrote:

> The CONFIG_RTE_LIBRTE_MEMPOOL_DEBUG and CONFIG_RTE_LIBRTE_MBUF_DEBUG
> didn't provide any input, so I also added the
> CONFIG_RTE_LIBRTE_ETHDEV_DEBUG and CONFIG_RTE_LIBRTE_IGB_PMD.
>
> below is a sample log showing the problem, though I don't see any clue in
> the logs.
> in this case pkt 58509 is placed at the place of pkt 58637...
> I also noted that the diff between the two packets is 128, and this is the
> case in most of the cases where it happens...
> the rx_id of the phantom pkt (58509) is 141 (port_id=0 queue_id=0
> rx_id=141 staterr=0x3 pkt_len=146)
>
> .....still digging
>
> port_id=0 queue_id=0 rx_id=264 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=265 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=266 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=267 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts(): port_id=0 queue_id=0 rx_tail=268 nb_hold=4
> nb_rx=4
>
>
> IM_LOG_VFLOWCOM: input: START_10 58632
>
> IM_LOG_VFLOWCOM: input: START_10 58633
>
> IM_LOG_VFLOWCOM: input: START_10 58634
>
> IM_LOG_VFLOWCOM: input: START_10 58635
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=268 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=269 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=270 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=271 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts(): port_id=0 queue_id=0 rx_tail=272 nb_hold=4
> nb_rx=4
>
>
> IM_LOG_VFLOWCOM: input: START_10 58636
>
> IM_LOG_VFLOWCOM: input: START_10 58509
>
> IM_LOG_VFLOWCOM: wrong pkt number arrived from burst 4, expected 58637 but
> got 58509
>
> IM_LOG_VFLOWCOM: input: START_10 58638
>
> IM_LOG_VFLOWCOM: input: START_10 58639
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=272 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=273 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=274 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts():
>
> port_id=0 queue_id=0 rx_id=275 staterr=0x3 pkt_len=146
>
>
> PMD: eth_igb_recv_pkts(): port_id=0 queue_id=0 rx_tail=276 nb_hold=4
> nb_rx=4
>
>
> IM_LOG_VFLOWCOM: input: START_10 58640
>
> IM_LOG_VFLOWCOM: input: START_10 58641
>
> IM_LOG_VFLOWCOM: input: START_10 58642
>
> IM_LOG_VFLOWCOM: input: START_10 58643
>
>
>
> On Wed, Jul 16, 2014 at 3:36 PM, Helmut Sim <simhelmut at gmail.com> wrote:
>
>> I will try it though I hope the amount of logs won't affect the result.
>> while analyzing the wireshark captures I noted that the packet i supposed
>> to capture arrives in a short time after the one before.
>> for example, here is a time between the consecutive transmitted packets:
>> 0.000050000 PKT 12201
>> 0.000050000 PKT 12202
>> 0.000050000 PKT 12203
>> 0.000050000 PKT 12204
>> 0.000050000 PKT 12205
>> 0.000050000 PKT 12206
>> 0.000020000 PKT 12207 ==> though this one was received at the app as "PKT
>> 12202"
>> 0.000050000 PKT 12208
>>
>> note that the problematic case was transmitted in a very short time after
>> its previous one. this is also the case in other problematic cases.
>>
>> is there any way to configure ethernet IFG (Interf Frame Gap)?
>>
>> Thanks,
>>
>>
>> On Wed, Jul 16, 2014 at 3:18 PM, Olivier MATZ <olivier.matz at 6wind.com>
>> wrote:
>>
>>> Hello Helmut,
>>>
>>>
>>> 2014-07-16 13:56, Helmut Sim:
>>>
>>>> then i see that from time to time i get a packet that was already
>>>>> received
>>>>> earlier instead of receiving the expected packet.
>>>>> the output is:
>>>>> PKT 12201
>>>>> PKT 12202
>>>>> PKT 12203
>>>>> PKT 12204
>>>>> PKT 12205
>>>>> PKT 12206
>>>>> PKT 12202
>>>>> PKT 12208
>>>>>
>>>>> total received pkts is identical to the total delivered pkts, but part
>>>>> of
>>>>> the pkts are being received twice...
>>>>>
>>>>
>>> Enabling CONFIG_RTE_LIBRTE_MEMPOOL_DEBUG and
>>> CONFIG_RTE_LIBRTE_MBUF_DEBUG could help you to track
>>> double free or corruptions.
>>>
>>> Regards,
>>> Olivier
>>>
>>>
>>
>