DPDK patches and discussions
 help / color / mirror / Atom feed
From: Venky Venkatesh <vvenkatesh@paloaltonetworks.com>
To: "Mattias Rönnblom" <mattias.ronnblom@ericsson.com>,
	"dev@dpdk.org" <dev@dpdk.org>
Subject: Re: [dpdk-dev] DSW eventdev is getting "stuck"?
Date: Thu, 4 Apr 2019 18:13:09 +0000	[thread overview]
Message-ID: <0C690BD4-CB1F-4556-B225-B753670B9E1F@paloaltonetworks.com> (raw)
Message-ID: <20190404181309.pPu-nqANJ7UinKirZYI90grKALuv3izRNLQ5WUBTlOU@z> (raw)
In-Reply-To: <7790bc0b-8c70-fa82-8d34-ba25dbaf226e@ericsson.com>



On 4/4/19, 12:40 AM, "Mattias Rönnblom" <mattias.ronnblom@ericsson.com> wrote:

    On 2019-04-04 07:39, Venky Venkatesh wrote:
    > 
    > 
    > On 4/3/19, 12:02 PM, "Mattias Rönnblom" <mattias.ronnblom@ericsson.com> wrote:
    > 
    >      On 2019-04-03 20:36, Venky Venkatesh wrote:
    >      >
    >      >
    >      > On 4/3/19, 11:34 AM, "Mattias Rönnblom" <mattias.ronnblom@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@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.

[VV]: Bingo! You nailed it. I checked the above in gdb. It is exactly what you said. Let me fix it and see. 
On a side note on the design, suppose you have 1 massive flow in terms of work per packet and is "long" lived. Then 1 core would be super busy while others would be idle. Then would it constantly consider migrating that flow since the busy-ness of the core would be above a threshold while others are idle? Again (after migrating) to figure out that the new core is super busy while others are idle and so on ...? A sort of thrashing effect.

Thanks
-Venky 


    
    > ------ 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'}}
    >      
    > 
    


  parent reply	other threads:[~2019-04-04 18:13 UTC|newest]

Thread overview: 16+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2019-04-03 18:17 Venky Venkatesh
2019-04-03 18:17 ` Venky Venkatesh
2019-04-03 18:33 ` Mattias Rönnblom
2019-04-03 18:33   ` Mattias Rönnblom
2019-04-03 18:36   ` Venky Venkatesh
2019-04-03 18:36     ` Venky Venkatesh
2019-04-03 19:02     ` Mattias Rönnblom
2019-04-03 19:02       ` Mattias Rönnblom
2019-04-04  5:39       ` Venky Venkatesh
2019-04-04  5:39         ` Venky Venkatesh
2019-04-04  7:39         ` Mattias Rönnblom
2019-04-04  7:39           ` Mattias Rönnblom
2019-04-04 18:13           ` Venky Venkatesh [this message]
2019-04-04 18:13             ` Venky Venkatesh
2019-04-04 19:29             ` Mattias Rönnblom
2019-04-04 19:29               ` Mattias Rönnblom

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=0C690BD4-CB1F-4556-B225-B753670B9E1F@paloaltonetworks.com \
    --to=vvenkatesh@paloaltonetworks.com \
    --cc=dev@dpdk.org \
    --cc=mattias.ronnblom@ericsson.com \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).