TRex stats showing required rate is not reached

[janbal...@gmail.com]

Hello,

I have a problem that TRex is not holding requested TX rate for the whole length of test duration.
For example I request rate 1Mpps for 60seconds in 4 streams (2 of it latency streams). I use the new 'get_pgid_stats' function to poll results every 10 seconds. Per stream stats are useful, but I also need to know total TX rate in pps for all of my streams - I sum together tx_pps of my streams.
At first tx_pps seems to be matching the requested rate ~0.5Mpps per port. But my last pollings show total only almost 0.5Mpps in total (~0.25Mpps per port).

What could be wrong? Here is output of the raw stats from late polling:
{'latency': {3: {'err_cntrs': {
'dup': 0,
'dropped': 0,
'out_of_order': 0,
'seq_too_low': 0,
'seq_too_high': 0,
}, 'latency': {
'last_max': 147,
'total_max': 441,
'average': 81.12103833436413,
'histogram': {
80: 4938,
100: 2354,
70: 5580,
200: 2,
300: 3,
400: 1,
40: 14,
50: 585,
20: 2,
90: 3531,
60: 2958,
30: 32,
},
'jitter': 15,
'total_min': 20,
}}, 'global': {'bad_hdr': 0, 'old_flow': 0}, 5: {'err_cntrs': {
'dup': 0,
'dropped': 0,
'out_of_order': 0,
'seq_too_low': 0,
'seq_too_high': 0,
}, 'latency': {
'last_max': 125,
'total_max': 335,
'average': 52.90818250739903,
'histogram': {
100: 190,
70: 1681,
200: 3,
10: 63,
300: 1,
80: 1916,
40: 6376,
50: 2950,
20: 450,
90: 972,
60: 1500,
30: 3898,
},
'jitter': 20,
'total_min': 10,
}}}, 'flow_stats': {
3: {
'rx_bps': {0: 0, 1: 531626.62, 'total': 531626.62},
'rx_pps': {0: 0, 1: 977.25, 'total': 977.25},
'rx_pkts': {0: 0, 1: 20000, 'total': 20000},
'rx_bytes': {0: 'N/A', 1: 'N/A', 'total': 'N/A'},
'tx_pkts': {0: 20000, 1: 0, 'total': 20000},
'tx_pps': {0: 500.23, 1: 0, 'total': 500.23},
'tx_bps': {0: 272122.56, 1: 0, 'total': 272122.56},
'tx_bytes': {0: 1360000, 1: 0, 'total': 1360000},
'rx_bps_l1': {0: 0.0, 1: 687986.62, 'total': 687986.62},
'tx_bps_l1': {0: 352159.36, 1: 0.0, 'total': 352159.36},
},
2: {
'rx_bps': {0: 0, 1: 0, 'total': 0},
'rx_pps': {0: 0, 1: 488409.94, 'total': 488409.94},
'rx_pkts': {0: 0, 1: 9980004, 'total': 9980004},
'rx_bytes': {0: 'N/A', 1: 'N/A', 'total': 'N/A'},
'tx_pkts': {0: 9980004, 1: 0, 'total': 9980004},
'tx_pps': {0: 249495.28, 1: 0, 'total': 249495.28},
'tx_bps': {0: 135725440, 1: 0, 'total': 135725440},
'tx_bytes': {0: 678640272, 1: 0, 'total': 678640272},
'rx_bps_l1': {0: 0.0, 1: 78145590.4, 'total': 78145590.4},
'tx_bps_l1': {0: 175644684.8, 1: 0.0, 'total': 175644684.8},
},
'global': {'rx_err': {0: 0, 1: 0}, 'tx_err': {0: 0, 1: 0}},
4: {
'rx_bps': {0: 0, 1: 0, 'total': 0},
'rx_pps': {0: 488468.25, 1: 0, 'total': 488468.25},
'rx_pkts': {0: 9980004, 1: 0, 'total': 9980004},
'rx_bytes': {0: 'N/A', 1: 'N/A', 'total': 'N/A'},
'tx_pkts': {0: 0, 1: 9980004, 'total': 9980004},
'tx_pps': {0: 0, 1: 249495.28, 'total': 249495.28},
'tx_bps': {0: 0, 1: 135725440, 'total': 135725440},
'tx_bytes': {0: 0, 1: 678640272, 'total': 678640272},
'rx_bps_l1': {0: 78154920.0, 1: 0.0, 'total': 78154920.0},
'tx_bps_l1': {0: 0.0, 1: 175644684.8, 'total': 175644684.8},
},
5: {
'rx_bps': {0: 532063, 1: 0, 'total': 532063},
'rx_pps': {0: 978.06, 1: 0, 'total': 978.06},
'rx_pkts': {0: 20000, 1: 0, 'total': 20000},
'rx_bytes': {0: 'N/A', 1: 'N/A', 'total': 'N/A'},
'tx_pkts': {0: 0, 1: 20000, 'total': 20000},
'tx_pps': {0: 0, 1: 500.23, 'total': 500.23},
'tx_bps': {0: 0, 1: 272124.56, 'total': 272124.56},
'tx_bytes': {0: 0, 1: 1360000, 'total': 1360000},
'rx_bps_l1': {0: 688552.6, 1: 0.0, 'total': 688552.6},
'tx_bps_l1': {0: 0.0, 1: 352161.36, 'total': 352161.36},
},
}, 'ver_id': {
u'3': 169,
u'2': 168,
u'5': 171,
u'4': 170,
}}

And here is one of the good iterations:
{'latency': {3: {'err_cntrs': {
'dup': 0,
'dropped': 0,
'out_of_order': 0,
'seq_too_low': 0,
'seq_too_high': 0,
}, 'latency': {
'last_max': 332,
'total_max': 441,
'average': 81.94624710083008,
'histogram': {
80: 2480,
100: 1234,
70: 2767,
200: 2,
300: 2,
400: 1,
40: 7,
50: 278,
20: 2,
90: 1796,
60: 1426,
30: 8,
},
'jitter': 13,
'total_min': 20,
}}, 'global': {'bad_hdr': 0, 'old_flow': 0}, 5: {'err_cntrs': {
'dup': 0,
'dropped': 0,
'out_of_order': 0,
'seq_too_low': 0,
'seq_too_high': 0,
}, 'latency': {
'last_max': 273,
'total_max': 335,
'average': 54.190439224243164,
'histogram': {
100: 99,
70: 866,
200: 2,
10: 31,
300: 1,
80: 942,
40: 3138,
50: 1565,
20: 228,
90: 481,
60: 751,
30: 1898,
},
'jitter': 30,
'total_min': 10,
}}}, 'flow_stats': {
3: {
'rx_bps': {0: 0, 1: 544171.81, 'total': 544171.81},
'rx_pps': {0: 0, 1: 1000.32, 'total': 1000.32},
'rx_pkts': {0: 0, 1: 10003, 'total': 10003},
'rx_bytes': {0: 'N/A', 1: 'N/A', 'total': 'N/A'},
'tx_pkts': {0: 10003, 1: 0, 'total': 10003},
'tx_pps': {0: 1000.32, 1: 0, 'total': 1000.32},
'tx_bps': {0: 544171.88, 1: 0, 'total': 544171.88},
'tx_bytes': {0: 680204, 1: 0, 'total': 680204},
'rx_bps_l1': {0: 0.0, 1: 704223.01, 'total': 704223.01},
'tx_bps_l1': {0: 704223.0800000001, 1: 0.0,
'total': 704223.0800000001},
},
2: {
'rx_bps': {0: 0, 1: 0, 'total': 0},
'rx_pps': {0: 0, 1: 498990.38, 'total': 498990.38},
'rx_pkts': {0: 0, 1: 4990594, 'total': 4990594},
'rx_bytes': {0: 'N/A', 1: 'N/A', 'total': 'N/A'},
'tx_pkts': {0: 4990696, 1: 0, 'total': 4990696},
'tx_pps': {0: 498987.81, 1: 0, 'total': 498987.81},
'tx_bps': {0: 271449408, 1: 0, 'total': 271449408},
'tx_bytes': {0: 339367328, 1: 0, 'total': 339367328},
'rx_bps_l1': {0: 0.0, 1: 79838460.8, 'total': 79838460.8},
'tx_bps_l1': {0: 351287457.6, 1: 0.0, 'total': 351287457.6},
},
'global': {'rx_err': {0: 0, 1: 0}, 'tx_err': {0: 0, 1: 0}},
4: {
'rx_bps': {0: 0, 1: 0, 'total': 0},
'rx_pps': {0: 498985.88, 1: 0, 'total': 498985.88},
'rx_pkts': {0: 4990440, 1: 0, 'total': 4990440},
'rx_bytes': {0: 'N/A', 1: 'N/A', 'total': 'N/A'},
'tx_pkts': {0: 0, 1: 4990510, 'total': 4990510},
'tx_pps': {0: 0, 1: 498987.81, 'total': 498987.81},
'tx_bps': {0: 0, 1: 271449408, 'total': 271449408},
'tx_bytes': {0: 0, 1: 339354680, 'total': 339354680},
'rx_bps_l1': {0: 79837740.8, 1: 0.0, 'total': 79837740.8},
'tx_bps_l1': {0: 0.0, 1: 351287457.6, 'total': 351287457.6},
},
5: {
'rx_bps': {0: 544171.88, 1: 0, 'total': 544171.88},
'rx_pps': {0: 1000.32, 1: 0, 'total': 1000.32},
'rx_pkts': {0: 10002, 1: 0, 'total': 10002},
'rx_bytes': {0: 'N/A', 1: 'N/A', 'total': 'N/A'},
'tx_pkts': {0: 0, 1: 10002, 'total': 10002},
'tx_pps': {0: 0, 1: 999.37, 'total': 999.37},
'tx_bps': {0: 0, 1: 543659.38, 'total': 543659.38},
'tx_bytes': {0: 0, 1: 680136, 'total': 680136},
'rx_bps_l1': {0: 704223.0800000001, 1: 0.0,
'total': 704223.0800000001},
'tx_bps_l1': {0: 0.0, 1: 703558.5800000001,
'total': 703558.5800000001},
},
}, 'ver_id': {
u'3': 169,
u'2': 168,
u'5': 171,
u'4': 170,
}}

But amount of packets received is correct - for example 1Mpps 10s run we receive 10M packets.

Btw. also with 2x10G interfaces, 3 cores for TRex, TRex is not able to send 100% load with 64B packets. We use Intel NIC x710.

Thank you for any pointers for solving this.

Jan

[hanoh haim]

Hi Jan,

Is it possible that your last query is done after the traffic was stopped? If yes. This is expected as the rate is low pass filter of the rate and should sample before you stop the traffic.

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 post to this group, send email to trex...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/trex-tgn/6cca2344-9e67-49bd-921f-d224a7da9b58%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Hanoh

Sent from my iPhone

[janbal...@gmail.com]

Yes, it's done after. How to get real TX rate for the whole period of test regardless of polling? Is it safe to assume that sum(RX packets) / time_requested will give me correct rate?

I note that I start traffic with 'duration' key and value for it provided. What would be the most precise way to get real TX rate for the test?

[hanoh haim]

You could do that. See other email about this question. In our scripts we take the rate before the traffic is stoped. The rate should be constant if there is no issue.

Thanks,

Hanoh

On Thu, 29 Jun 2017 at 13:55 <janbal...@gmail.com> wrote:

Yes, it's done after. How to get real TX rate for the whole period of test regardless of polling? Is it safe t

sume that sum(RX packets) / time_requested will give me correct rate?

!

I note that I start traffic with 'duration' key and value for it provided. What would be the most precise way to get real TX rate for the test?

--
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 post to this group, send email to trex...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/trex-tgn/3a00c3b1-9f7e-4e7f-a1fb-f3a5f0b4448d%40googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

[hanoh haim]

There is one small pitfall with total_bytes*8/time proposal. The time in rare cases might not be the time you think.

For example if you gave 60 sec don't take it for granted, in some cases it could be 70sec because scheduler can't handle the rate. 

Now measuring the time in python is not accurate in ~msec so in case of short periods it  could create high inaccuracy (in your case it would be .1% )

More thinking about it, even in the server the time can't be taken in accurate way given multicore for short times.

Need to think how to solve this

Thanks,

Hanoh