[dpdk-dev] DSW eventdev is getting "stuck"?
Mattias Rönnblom
mattias.ronnblom at ericsson.com
Thu Apr 4 09:39:50 CEST 2019
On 2019-04-04 07:39, Venky Venkatesh wrote:
>
>
> On 4/3/19, 12:02 PM, "Mattias Rönnblom" <mattias.ronnblom at ericsson.com> wrote:
>
> On 2019-04-03 20:36, Venky Venkatesh wrote:
> >
> >
> > On 4/3/19, 11:34 AM, "Mattias Rönnblom" <mattias.ronnblom at ericsson.com> wrote:
> >
> > On 2019-04-03 20:17, Venky Venkatesh wrote:
> > > Hi,
> > > I am using the DSW code from 18.11 with the default settings for all the #defines. Here are some more details:
> > > I have an 8 port system with 1 queue.
> > > All ports can inject events. Port 0 and 7 inject events rarely.
> > > Ports 1-6 are linked to the queue and hence dequeue events.
> > >
> > > I see that in steady state the total number enqueues into the system is much greater than the total number of dequeues.
> > > eventdev deq#: 1948491 enq#: 1949007
> > >
> >
> > If you have more enqueues than dequeues, it means there are events in
> > flight in the scheduler. In the above case, it's roughly 516 events,
> > which sounds perfectly healthy and normal. I say roughly, because
> > there's no way to take a consistent, global snapshot of all xstats counters.
> >
> > [VV]: This is in steady state i.e. there are no more events being injected into the system. So shouldn’t everything get drained out at some point?
> >
>
> Assuming appropriate application behavior, sure, of course.
>
> Events in flight are either in the output buffer on the producer port,
> or the input ring on the consumer.
>
> Inappropriate behavior would be if any port (producer, consumer or
> producer+consumer) is left unattended (i.e. no enqueue or dequeue
> operation is performed).
>
> [VV]: I am pasting the original data again below. If about 516 events are inflight, atleast a few should show up in one of the data structures that you refer to -- but they don’t as seen below. Isn't that odd? Do you have any other places I can look -- there were no migrations too to look at some other transient buffers.
>
> Below are the counters:
>
> [root at PA-VM-venky ~]# cat y
> dev_credits_on_loan: 883
> ------ port 0 --------
> port_0_new_enqueued: 125
> port_0_forward_enqueued: 0
> port_0_release_enqueued: 0
> port_0_queue_0_enqueued: 125
> port_0_dequeued: 0
> port_0_queue_0_dequeued: 0
> port_0_migrations: 0
Zero migrations? Looks suspicions, unless you've had a very light load
throughout the duration of the test.
> port_0_migration_latency: 0
> port_0_event_proc_latency: 0
> port_0_inflight_credits: 3
> port_0_load: 49
> port_0_last_bg: 39368511869708
This is an unattended port. "last_bg" is a timestamp of when this port
last checked for ongoing "background operations" (included just for the
purpose of finding offending ports). A background operation is handling
the signaling required for migration to progress, or flushing the output
buffers - for producers going idle.
If you compare this "last_bg" the others', you'll see that this port has
been idle for something like 3.8e+13 TSC cycles. Assuming 2,4 GHz TSC
clock, this port hasn't received any love in ~4h.
An unattended port blocks completion of a migration. This in turn means
that there might well be events sitting in the "paused_events" array at
the various ports, related to the in-progress migration. Check
"paused_events_len" in gdb to verify that this is indeed the case.
> ------ port 1 --------
> port_1_new_enqueued: 138947
> port_1_forward_enqueued: 237896
> port_1_release_enqueued: 0
> port_1_queue_0_enqueued: 376843
> port_1_dequeued: 475778
> port_1_queue_0_dequeued: 475778
> port_1_migrations: 0
> port_1_migration_latency: 0
> port_1_event_proc_latency: 119069
> port_1_inflight_credits: 13
> port_1_load: 0
> port_1_last_bg: 77183632541672
> ------ port 2 --------
> port_2_new_enqueued: 88834
> port_2_forward_enqueued: 156687
> port_2_release_enqueued: 0
> port_2_queue_0_enqueued: 245521
> port_2_dequeued: 313358
> port_2_queue_0_dequeued: 313358
> port_2_migrations: 0
> port_2_migration_latency: 0
> port_2_event_proc_latency: 176184
> port_2_inflight_credits: 15
> port_2_load: 0
> port_2_last_bg: 77183632941696
> ------ port 3 --------
> port_3_new_enqueued: 73170
> port_3_forward_enqueued: 78087
> port_3_release_enqueued: 0
> port_3_queue_0_enqueued: 151257
> port_3_dequeued: 165317
> port_3_queue_0_dequeued: 165317
> port_3_migrations: 0
> port_3_migration_latency: 0
> port_3_event_proc_latency: 329601
> port_3_inflight_credits: 66
> port_3_load: 0
> port_3_last_bg: 77183632966910
> ------ port 4 --------
> port_4_new_enqueued: 93182
> port_4_forward_enqueued: 76422
> port_4_release_enqueued: 0
> port_4_queue_0_enqueued: 169604
> port_4_dequeued: 207721
> port_4_queue_0_dequeued: 207721
> port_4_migrations: 0
> port_4_migration_latency: 0
> port_4_event_proc_latency: 262259
> port_4_inflight_credits: 114
> port_4_load: 0
> port_4_last_bg: 77183632760588
> ------ port 5 --------
> port_5_new_enqueued: 144855
> port_5_forward_enqueued: 630897
> port_5_release_enqueued: 0
> port_5_queue_0_enqueued: 775752
> port_5_dequeued: 633700
> port_5_queue_0_dequeued: 633700
> port_5_migrations: 0
> port_5_migration_latency: 0
> port_5_event_proc_latency: 88203
> port_5_inflight_credits: 64
> port_5_load: 0
> port_5_last_bg: 77183632277448
> ------ port 6 --------
> port_6_new_enqueued: 153590
> port_6_forward_enqueued: 76315
> port_6_release_enqueued: 0
> port_6_queue_0_enqueued: 229905
> port_6_dequeued: 152617
> port_6_queue_0_dequeued: 152617
> port_6_migrations: 0
> port_6_migration_latency: 0
> port_6_event_proc_latency: 354408
> port_6_inflight_credits: 92
> port_6_load: 0
> port_6_last_bg: 77183632653092
> ------ port 7 --------
> port_7_new_enqueued: 0
> port_7_forward_enqueued: 0
> port_7_release_enqueued: 0
> port_7_queue_0_enqueued: 0
> port_7_dequeued: 0
> port_7_queue_0_dequeued: 0
> port_7_migrations: 0
> port_7_migration_latency: 0
> port_7_event_proc_latency: 0
> port_7_inflight_credits: 0
> port_7_load: 0
Where's the "last_bg" for this port?
>
>
>
> Below are the data structure values:
>
> (gdb) p ((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[0]->out_buffer_len
> $2 = {0 <repeats 64 times>}
> (gdb) p ((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[1]->out_buffer_len
> $3 = {0 <repeats 64 times>}
> (gdb) p ((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[2]->out_buffer_len
> $4 = {0 <repeats 64 times>}
> (gdb) p ((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[3]->out_buffer_len
> $5 = {0 <repeats 64 times>}
> (gdb) p ((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[4]->out_buffer_len
> $6 = {0 <repeats 64 times>}
> (gdb) p ((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[5]->out_buffer_len
> $7 = {0 <repeats 64 times>}
> (gdb) p ((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[6]->out_buffer_len
> $8 = {0 <repeats 64 times>}
> (gdb) p ((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[7]->out_buffer_len
> $9 = {0 <repeats 64 times>}
> (gdb) p *((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[0]->in_ring
> $10 = {r = {name = "dsw0_p0", '\000' <repeats 24 times>, flags = 6, memzone = 0xc000000090, size = 32768, mask = 32767, capacity = 16384, pad0 = 0 '\000', prod = {head = 0, tail = 0,
> single = 0}, pad1 = 0 '\000', cons = {head = 0, tail = 0, single = 1}, pad2 = 0 '\000'}}
> (gdb) p *((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[1]->in_ring
> $11 = {r = {name = "dsw0_p1", '\000' <repeats 24 times>, flags = 6, memzone = 0xc000000120, size = 32768, mask = 32767, capacity = 16384, pad0 = 0 '\000', prod = {head = 475778,
> tail = 475778, single = 0}, pad1 = 0 '\000', cons = {head = 475778, tail = 475778, single = 1}, pad2 = 0 '\000'}}
> (gdb) p *((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[2]->in_ring
> $12 = {r = {name = "dsw0_p2", '\000' <repeats 24 times>, flags = 6, memzone = 0xc0000001b0, size = 32768, mask = 32767, capacity = 16384, pad0 = 0 '\000', prod = {head = 313358,
> tail = 313358, single = 0}, pad1 = 0 '\000', cons = {head = 313358, tail = 313358, single = 1}, pad2 = 0 '\000'}}
> (gdb) p *((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[3]->in_ring
> $13 = {r = {name = "dsw0_p3", '\000' <repeats 24 times>, flags = 6, memzone = 0xc000000240, size = 32768, mask = 32767, capacity = 16384, pad0 = 0 '\000', prod = {head = 165403,
> tail = 165403, single = 0}, pad1 = 0 '\000', cons = {head = 165403, tail = 165403, single = 1}, pad2 = 0 '\000'}}
> (gdb) p *((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[4]->in_ring
> $14 = {r = {name = "dsw0_p4", '\000' <repeats 24 times>, flags = 6, memzone = 0xc0000002d0, size = 32768, mask = 32767, capacity = 16384, pad0 = 0 '\000', prod = {head = 208237,
> tail = 208237, single = 0}, pad1 = 0 '\000', cons = {head = 208237, tail = 208237, single = 1}, pad2 = 0 '\000'}}
> (gdb) p *((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[5]->in_ring
> $15 = {r = {name = "dsw0_p5", '\000' <repeats 24 times>, flags = 6, memzone = 0xc000000360, size = 32768, mask = 32767, capacity = 16384, pad0 = 0 '\000', prod = {head = 633700,
> tail = 633700, single = 0}, pad1 = 0 '\000', cons = {head = 633700, tail = 633700, single = 1}, pad2 = 0 '\000'}}
> (gdb) p *((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[6]->in_ring
> $16 = {r = {name = "dsw0_p6", '\000' <repeats 24 times>, flags = 6, memzone = 0xc0000003f0, size = 32768, mask = 32767, capacity = 16384, pad0 = 0 '\000', prod = {head = 152617,
> tail = 152617, single = 0}, pad1 = 0 '\000', cons = {head = 152617, tail = 152617, single = 1}, pad2 = 0 '\000'}}
> (gdb) p *((struct dsw_evdev *)rte_eventdevs[0].data->dev_private)->ports[7]->in_ring
> $17 = {r = {name = "dsw0_p7", '\000' <repeats 24 times>, flags = 6, memzone = 0xc000000480, size = 32768, mask = 32767, capacity = 16384, pad0 = 0 '\000', prod = {head = 0, tail = 0,
> single = 0}, pad1 = 0 '\000', cons = {head = 0, tail = 0, single = 1}, pad2 = 0 '\000'}}
>
>
More information about the dev
mailing list