Latency stats drops few packets received.Need help in debugging further

[chris...@gmail.com]

Hi ,

I am sending custom traffic from trex to DUT .On receiving back the traffic from DUT,capture shows all the packets on trex but the latency stats is dropping 4 packets.

 How can i debug further to figure out why these 4 packets were dropped in latency stats?

Trex version used : v2.65

- port_limit: 2

  version   : 2

  c         : 1

  interfaces: ['00:09.0', 'dummy']

  stack     : linux_based

Namespace used:

trex(service)>ns show-node --mac 00:00:00:6d:b0:2d -p 0

Setting port 0 in with namespace configuration               [SUCCESS]

wait_for_async_results                                       [SUCCESS]

{u'nodes': [{u'ether': {u'src': u'00:00:00:6d:b0:2d'},

             u'ipv4': {u'dst': u'122.20.20.10', u'src': u'122.20.20.30'},

             u'ipv6': {u'enabled': True, u'src': u'2122::2300'},

             u'is_bird': False,

             u'linux-ns': u'trex-a-0-1e',

             u'linux-veth-external': u'trex-a-0-1e-T',

             u'linux-veth-internal': u'trex-a-0-1e-L',

             u'vlan': {u'tags': [1231], u'tpids': []}}]}

trex(service)>

Packet sent :

A custom header over ethernet.

stream = STLStream(packet = STLPktBuilder(pkt = packet, vm = vm),stream_id = 172,name = 'n_uplane_ul_122',mode =STLTXSingleBurst(total_pkts = 100,bps_L1 = 10000000.0),flow_stats = STLFlowLatencyStats(pg_id = 172))

trex(service)>stats --lh

Latency Histogram

   PG ID     |      172       

-------------+---------------

             |                

             |                

             |                

             |                

             |                

             |                

             |                

             |                

             |                

             |                

             |                

             |                

             |                

             |                

             |                

             |                

100          |             96 

- Counters - |                

dropped      |              4 

dup          |              0 

out_of_order |              0 

seq_too_high |              1 

seq_too_low  |              0 

trex(service)>stats -s

Streams Statistics

  PG ID    |        172        

-----------+------------------

Tx pps     |             0 pps 

Tx bps L2  |             0 bps 

Tx bps L1  |             0 bps 

---        |                   

Rx pps     |             0 pps 

Rx bps     |             0 bps 

----       |                   

opackets   |               100 

ipackets   |                96 

obytes     |            150000 

ibytes     |            141312 

-----      |                   

opackets   |          100 pkts 

ipackets   |           96 pkts 

obytes     |            150 KB 

ibytes     |         141.31 KB 

trex(service)>stats

Global Statistitcs

connection   : localhost, Port 4501                  total_tx_L2  : 2.23 Kb/sec                    

version      : STL @ v2.64                           total_tx_L1  : 2.26 Kb/sec                    

cpu_util.    : 0.01% @ 1 cores (1 per dual port)     total_rx     : 2.19 Kb/sec                    

rx_cpu_util. : 0.0% / 0.19 pkt/sec                   total_pps    : 0.19 pkt/sec                   

async_util.  : 0.08% / 1.25 KB/sec                   drop_rate    : 0 b/sec                        

total_cps.   : 0 cps/sec                             queue_full   : 0 pkts                         

Port Statistics

   port    |         0         

-----------+------------------

owner      |              root 

link       |                UP 

state      |              IDLE 

speed      |           10 Gb/s 

CPU util.  |              0.0% 

--         |                   

Tx bps L2  |         2.23 Kbps 

Tx bps L1  |         2.26 Kbps 

Tx pps     |          0.19 pps 

Line Util. |               0 % 

---        |                   

Rx bps     |         2.19 Kbps 

Rx pps     |          0.19 pps 

----       |                   

opackets   |               100 

ipackets   |               100 

obytes     |            150000 

ibytes     |            147200 

tx-pkts    |          100 pkts 

rx-pkts    |          100 pkts 

tx-bytes   |            150 KB 

rx-bytes   |          147.2 KB 

-----      |                   

oerrors    |                 0 

ierrors    |                 0 

The port stats and the capture shows all the 100 packets received wherein the latency stats drops 4 packets .How can i debug this further ? 

Thanks,

Chris

[hanoh haim]

Maybe your DUT change the packets? The metadata information is located inside the packet payload . Try in loopback to verify that this is the DUT

--
You received this message because you are subscribed to the Google Groups "TRex Traffic Generator" group.
To unsubscribe from this group and stop receiving emails from it, send an email to trex-tgn+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/trex-tgn/8638f869-d4b8-402b-943d-16d37d743095n%40googlegroups.com.

--

Hanoh

Sent from my iPhone

[chris...@gmail.com]

Hi Hanoh ,

I have checked the packet for 0xab and the following bytes.

It has ab:07:00:00 .Are these the four bytes which are used for tracking ?

Also, another observation is that when i send 10 packets , all 10 are shown in stats -s.Wherein when it is 100 , it drops 4 .If its 1000 it drops 16 packets .

I will anyways crosscheck the packets again .Any hints further ?

Is there a better way to debug the drop ?

Thanks,

Chris.

[hanoh haim]

Did you verify that without the DUT there are no drop? 

I would try the latest trex version which we add more verification to the packets 

Thanks

Hanoh

To view this discussion on the web visit https://groups.google.com/d/msgid/trex-tgn/08fe4167-05d1-4a5a-a9b3-fa1ee912e477n%40googlegroups.com.

[hanoh haim]

One more thing, verify the ipv4.Id ==0xffff 

[chris...@gmail.com]

Hi Hanoch ,

When 1000 packets are sent , I verified the bytes after 0xab for all the packets .They are the same in the transmitted and received packets. 

The transmitted packets are not ip packets , they are custom headers over ethernet .Hence there is no ipv4.Id . These packets enter the dut and get converted to ip packets within dut and come back to trex. Attached are the bytes after 0xab.

In addition to trex package we have  custom python automation api changes and custom scapy headers ,so do not want to move now to a latest version as there are cases running on v2.65. Anyways in one of the setups i shall upgrade and verify .Meanwhile any other suggestions to check these dropped packets.

Thanks,

Chris.

[hanoh haim]

Hi Chris, 

I missed something from your first email. FlowStats has a mechanism to verify order, in your case the order or the rx packets (after the DUT) are not in the same order of tx side. 

e.g. 

tx seq numbers of 1,2,3,4,5,6 and we get rx 1,5,2,3,4,6 the LatencyStats will report drop=4 and seq_to_high=1 

Now I don't know what you are testing and it is valid to have OOO (out of order) in the rx path, but if it is valid try to create a stream per each flow 

Thanks

Hanoh

[chris...@gmail.com]

Hi Hanoh,

Thanks . 

How is the sequence set on the transmitted packets ? Which field in the packet is edited for the same ? 

I have created one stream per flow .It is a custom packet over ethernet which is transmitted at the rate of 1000 pps. Any other suggestion to overcome this ?

Below are the latency stats  on trex on sending 1000 pkts. Can you please help me understand as to what do the numbers marked in green (5000,4000,200,100,90) indicate?

Sometimes i also see seq_too_low set .What does that mean ?

5000         |              1 

4000         |              1 

200          |              5 

100          |            946 

90           |             31 

- Counters - |                

dropped      |             16 

dup          |              0 

out_of_order |              0 

seq_too_high |              4 

seq_too_low  |              0 

Thanks,

Chris.

[hanoh haim]

Hi Cris, 

The numbers in the table are histogram of latency, e.g. it means that 1 packet has 5000-6000 usec latency, 946 packets have a 100-200 usec latency. 

The seq number is set on tx side and checked on rx side. is it part of the last 16 bytes, if needed I can give the exact format. 0xAB start the 16 bytes (it is the first byte), try to look for a seq number in the capture data 

this is from the spec

• "The last 16 bytes of the packet payload are used to pass needed information: ID of the stream, packet sequence number (per stream), timestamp of packet transmission."

[chris...@gmail.com]

Thanks Hanoh .In the .txt which i had attached earlier, shows the last 16bytes received at dut and tx by dut .

dut_ul_entry_all.txt ====> captured at the entry point of DUT  (sequence is fe,ff,00,01 ......These are the bytes transmitted by trex)

trex_ul_988_all.txt =====> packets received back by trex  from DUT (order seems  to be the same  as transmitted fe,ff,00,01 and so on )

I will debug further ,but from these two .txt files attached can you please check if they have the expected order? Is my understanding right ?

[hanoh haim]

The files look identical and does not match the counters you are showing. Maybe the rate is different 

Thanks

Hanoh

[Chris Jane]

The files are for 1000 pps.

[hanoh haim]

Hi Chris,

To be sure, in 1000pps (the rate that you capture) you don't see a 'drop' indication in the counters right?

Thanks

Hanoh

[chris...@gmail.com]

Hi Hanoh ,

For 1000pps as well a drop of 16 is seen consistently.

For the bytes attached in the text , the latency counters on trex were as below:

4000         |              1 

1000         |              1 

500          |              1 

100          |            351 

90           |            569 

80           |             61 

- Counters - |                

dropped      |             16 

dup          |              0 

out_of_order |              0 

seq_too_high |              4 

seq_too_low  |              0 

In all the outputs ,though drops are displayed out_of_order is 0 .Does that signify something ?

Thanks,

Chris.

[hanoh haim]

Hi Chris, 

This is strange .. if the capture has all the 1000 packets it means it reached the software in the same order. 

If you are familiar with c++ I would add some debug info into the code of the latency. 

If you can capture the full traffic  (as pcap file) of 100 packets ( I see that even with 100 packets you have 4 drop reportede) I could replay it on one of our setup to find the issue. 

BTW can you say what is the driver name and the command to launch trex that you are using?

You should use --software to be able to use the latency/eth feature

Thanks

Hanoh

[chris...@gmail.com]

Hi Hanoh,

I am not comfortable with C++ .Anyways , i will try adding some debugs to the latency code and check .

Below are the requested outputs:

./dpdk_setup_ports.py -s

Network devices using DPDK-compatible driver

============================================

0000:00:09.0 'Virtio network device' drv=igb_uio unused=virtio_pci,vfio-pci,uio_pci_generic

./t-rex-64 -i --software

- port_limit: 2

  version   : 2

  c         : 1

  interfaces: ['00:09.0', 'dummy']

  stack     : linux_based

The packets rcvd on trex are attached.

Thanks,

Chris.

[Hanoch Haim]

The c++ code start here, I would add some debug to see where is the error 

void RXLatency::handle_pkt(const rte_mbuf_t *m, int port) {

CFlowStatParser parser(CFlowStatParser::FLOW_STAT_PARSER_MODE_SW);

parser.set_vxlan_skip(CGlobalInfo::m_options.m_ip_cfg[port].get_vxlan_fs());

int res = parser.parse(rte_pktmbuf_mtod(m, uint8_t *), m->pkt_len);

[hanoh haim]

Hi Chris, 

The file you have attached was captured in the tx side right (as I see dot1q/ip/udp/gtpu) ? Can you send the one that was captured by trex in the Rx side (without ip). 

try to reproduce with 100 packets 

Thanks

Hanoh

[chris...@gmail.com]

The pcap sent was the packets received back by Trex from DUT.

The transmitted packets are custom packets which got converted in DUT to the above attached gtpu packets.

I shall shortly send the capture for 100 packets.

[hanoh haim]

Hi Chris,

This issue was fixed,

The problem is that you convert the packets to ipv4/udp which has a ipv4.id

ipv4.id is given priority over the latency check (last 16bytes) in the old versions

uint16_t hw_id = get_hw_id((uint16_t)ip_id);

if (hw_id < MAX_FLOW_STATS) {

m_rx_pg_stat[hw_id].add_pkts(1);

m_rx_pg_stat[hw_id].add_bytes(m->pkt_len +

4);

The ipv4.id that you generate is random and some hit this case and skip the latency function ..

In v2.89+ this has been fixed and the latency header has a priority and we added more checked in the 16 bytes 

Thanks

Hanoh

[chris...@gmail.com]

Thanks Hanoh.

I shall upgrade and then get back.

[hanoh haim]

Hi Chris, 

One more thing, 

If you have control of the DUT packet conversion function, you can try to change the ipv4.id value to 0xFFFF 

Thanks

Hanoh

[chris...@gmail.com]

Hi Hanoh,

Thanks much for the support . After upgrade to v2.90, it worked.

The dut's functionality cannot be  modified.

Thanks,

Chris.

[hanoh haim]

Hi Chris, 

Just to clarify that this functionality is a corner case that was changed in v2.89.

We define support for ipv4.id ==0xffff as a filter for ip packets and L7 payload for non-ip packets but we didn't define what happen in case and ip packet that has a payload .. (you case)

What is the priority? in v2.89 we hardened the L7 header verification and gave it priority and this is the reason it works for you.

Thanks

Hanoh

--

You received this message because you are subscribed to the Google Groups "TRex Traffic Generator" group.
To unsubscribe from this group and stop receiving emails from it, send an email to trex-tgn+u...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/trex-tgn/1433df95-461b-445b-8964-15203adcb8b6n%40googlegroups.com.

[chris...@gmail.com]

Hi @Hanoh , 

Very sorry to come back so late. The statistics implementation which you mentioned as missing , is it available now ?

To summarize:

non-ip packet (tx ) --- DUT (converts to ip packets) ----> stats -s (doesnt show all the count , wherein trex capture shows all packets ) - I have also created a new post for same -  Latency stats doesn't show all the packets, though capture has all the packets

If this is not already handled , could you please suggest me some fix which i can try ? I am using the latest trex (3.06) .
Thanks,

Chris.

[hanoh haim]

Hi Chris, the new versions are only DPDK upgrades 

Thanks, 

Hanoh

Sent from my iPhone

To view this discussion visit https://groups.google.com/d/msgid/trex-tgn/bc893fca-8910-4ce5-9ecc-f5912f8f2aa0n%40googlegroups.com.

[chris...@gmail.com]

Thanks Hanoh for the response . 

Could you brief me the root cause for this issue , so that i can see if i can fix it on my own ?