> -----Original Message----- > From: William Tu <[email protected]> > Sent: Wednesday, May 20, 2020 3:20 PM > To: Van Haaren, Harry <[email protected]> > Cc: [email protected]; [email protected] > Subject: Re: [ovs-dev] [PATCH v2 5/5] dpif-lookup: add avx512 gather > implementation
<snip snip> > > > > > > 3) start ovs and set avx and traffic gen > > > ovs-appctl dpif-netdev/subtable-lookup-set avx512_gather 5 > > > ovs-vsctl add-port br0 tg0 -- set int tg0 type=dpdk > > > options:dpdk- > devargs=vdev:net_pcap0,rx_pcap=/root/ovs/p0.pcap,infinite_rx=1 > > > > The output of the first command (enabling the AVX512 lookup) posts some > output to Log INFO, please ensure its there? > > > > 2020-05-20T09:39:09Z|00262|dpif_netdev_lookup|INFO|Subtable function > 'avx512_gather' set priority to 4 > > 2020-05-20T09:39:09Z|00006|dpif_netdev(pmd-c15/id:99)|INFO|reprobing sub > func, 5 1 > > > Yes, got these info log. OK - verified the AVX512 is plugging in correct, moving on. > ovs-vsctl -- add-br br0 -- set Bridge br0 datapath_type=netdev > ovs-vsctl set Open_vSwitch . other_config:pmd-cpu-mask=0x3 > ovs-vsctl --no-wait set Open_vSwitch . other_config:dpdk-init=true > ovs-ofctl add-flow br0 'actions=drop' > ovs-appctl dpif-netdev/subtable-lookup-set avx512_gather 5 > ovs-vsctl add-port br0 tg0 -- set int tg0 type=dpdk \ > options:dpdk- > devargs=vdev:net_pcap0,rx_pcap=/root/ovs/p0.pcap,infinite_rx=1 I use Ether/VLAN/IPv4 to achieve a subtable with (4,1), is that the same as you? Just trying to remove variables between our setups. > LOG: > 2020-05-20T13:49:26.542Z|00047|dpdk|INFO|DPDK Enabled - initialized > 2020-05-20T13:49:26.544Z|00048|connmgr|INFO|br0<->unix#2: 1 flow_mods > in the last 0 s (1 adds) > 2020-05-20T13:49:26.547Z|00049|dpif_netdev_lookup|INFO|Subtable > function 'avx512_gather' set priority to 5 > 2020-05-20T13:49:26.553Z|00050|netdev_dpdk|INFO|Device > 'vdev:net_pcap0,rx_pcap=/root/ovs/p0.pcap,infinite_rx=1' attached to > DPDK > 2020-05-20T13:49:26.553Z|00051|dpif_netdev|INFO|PMD thread on numa_id: > 0, core id: 0 created. > 2020-05-20T13:49:26.554Z|00052|dpif_netdev|INFO|PMD thread on numa_id: > 0, core id: 1 created. > 2020-05-20T13:49:26.554Z|00053|dpif_netdev|INFO|There are 2 pmd > threads on numa node 0 > 2020-05-20T13:49:26.554Z|00054|dpdk|INFO|Device with port_id=0 already > stopped > 2020-05-20T13:49:26.648Z|00055|netdev_dpdk|WARN|Rx checksum offload is > not supported on port 0 > 2020-05-20T13:49:26.648Z|00056|netdev_dpdk|WARN|Interface tg0 does not > support MTU configuration, max packet size supported is 1500. > 2020-05-20T13:49:26.648Z|00057|netdev_dpdk|INFO|Port 0: 02:70:63:61:70:00 > 2020-05-20T13:49:26.648Z|00058|dpif_netdev|INFO|Core 0 on numa node 0 > assigned port 'tg0' rx queue 0 (measured processing cycles 0). > 2020-05-20T13:49:26.648Z|00059|bridge|INFO|bridge br0: added interface > tg0 on port 1 > 2020-05-20T13:49:26.648Z|00001|ofproto_dpif_upcall(pmd- > c00/id:9)|WARN|upcall_cb > failure: ukey installation fails > 2020-05-20T13:49:27.562Z|00002|dpif_netdev(pmd-c00/id:9)|INFO|reprobing > sub func, 4 1 Aha! This shows somethings going wrong - there should not be any ukey-install fails! This also explains why your logs (as per follow-up email in thread) have a high upcall count/sec, the installed flow isn't being hit when matched. I'm not sure what the root cause of these ukey-installation fails are - but this is what we need to investigate :) Understanding the traffic, and attempting to reproduce here would a good step forward. Would you describe the traffic contained in the pcap? Is it a single packet, or something that should hit a single DPCLS wildcarded flow? > > > 4) dp flows with miniflow info > <snip> > > It seems the "packets:0, bytes:0,used:never" tags indicate that there is no > traffic hitting these rules at all? > > Output here (with traffic running for a while) shows: > > packets:621588543, bytes:37295312580, used:0.000s, dp:ovs, actions:dpdk1, > dp-extra-info:miniflow_bits(4,1) > > > Thanks, this is the hit rules: > root@instance-3:~/ovs# ovs-appctl dpctl/dump-flows -m | grep -v never > flow-dump from pmd on cpu core: 0 > ufid:f06998a0-9ff8-4ee5-b12f-5d7e2fcc7f0f, > skb_priority(0/0),skb_mark(0/0),ct_state(0/0),ct_zone(0/0),ct_mark(0/0),ct_label( > 0/0),recirc_id(0),dp_hash(0/0),in_port(tg0),packet_type(ns=0,id=0),eth(src=42:01: > 0a:b6:00:01/00:00:00:00:00:00,dst=42:01:0a:b6:00:02/00:00:00:00:00:00),eth_type > (0x0800),ipv4(src=169.254.169.254/0.0.0.0,dst=10.182.0.2/0.0.0.0,proto=6/0,tos= > 0/0,ttl=64/0,frag=no),tcp(src=80/0,dst=51642/0),tcp_flags(0/0), > packets:3942096, bytes:2511115152, used:0.001s, flags:P., dp:ovs, > actions:drop, dp-extra-info:miniflow_bits(4,1) > ufid:cb3a6eac-3a7d-4e0d-a145-414dd482b4b9, > skb_priority(0/0),skb_mark(0/0),ct_state(0/0),ct_zone(0/0),ct_mark(0/0),ct_label( > 0/0),recirc_id(0),dp_hash(0/0),in_port(tg0),packet_type(ns=0,id=0),eth(src=42:01: > 0a:b6:00:01/00:00:00:00:00:00,dst=42:01:0a:b6:00:02/00:00:00:00:00:00),eth_type > (0x0800),ipv4(src=169.254.169.254/0.0.0.0,dst=10.182.0.2/0.0.0.0,proto=6/0,tos= > 0/0,ttl=64/0,frag=no),tcp(src=80/0,dst=51650/0),tcp_flags(0/0), > packets:2779552, bytes:172332224, used:0.000s, flags:S., dp:ovs, > actions:drop, dp-extra-info:miniflow_bits(4,1) > ufid:781f3f48-ffd7-424f-ae99-62158ba05cbd, > skb_priority(0/0),skb_mark(0/0),ct_state(0/0),ct_zone(0/0),ct_mark(0/0),ct_label( > 0/0),recirc_id(0),dp_hash(0/0),in_port(tg0),packet_type(ns=0,id=0),eth(src=42:01: > 0a:b6:00:02/00:00:00:00:00:00,dst=42:01:0a:b6:00:01/00:00:00:00:00:00),eth_type > (0x0800),ipv4(src=10.182.0.2/0.0.0.0,dst=169.254.169.254/0.0.0.0,proto=6/0,tos= > 0/0,ttl=64/0,frag=no),tcp(src=51650/0,dst=80/0),tcp_flags(0/0), > packets:637373, bytes:216706820, used:0.000s, flags:P., dp:ovs, > actions:drop, dp-extra-info:miniflow_bits(4,1) If single DPCLS rule expected, the below dumps of 3 rules active is explained too. > > > 5) pmd-stat-show > > > root@instance-3:~/ovs# ovs-appctl dpif-netdev/pmd-stats-show > > > pmd thread numa_id 0 core_id 0: > > > packets received: 19838528 > > > packet recirculations: 0 > > > avg. datapath passes per packet: 1.00 > > > emc hits: 0 > > > smc hits: 0 > > > megaflow hits: 0 > > > avg. subtable lookups per megaflow hit: 0.00 (---> this doesn't > > > look right ....) > > > miss with success upcall: 78 > > > miss with failed upcall: 19838418 > > > avg. packets per output batch: 2.00 > > > idle cycles: 0 (0.00%) > > > processing cycles: 103431787838 (100.00%) > > > avg cycles per packet: 5213.68 (103431787838/19838528) > > > avg processing cycles per packet: 5213.68 (103431787838/19838528) > > > > Would you try the pmd-stats-show command before setting the AVX512 > lookup? > > If the issue is still present it would indicate its not related to the > > exact lookup > > implementation. > > Before setting AVX512 > ### Scalar Lookup > pmd thread numa_id 0 core_id 0: > packets received: 77470176 > packet recirculations: 0 > avg. datapath passes per packet: 1.00 > emc hits: 70423947 > smc hits: 0 > megaflow hits: 7045897 > avg. subtable lookups per megaflow hit: 1.00 > miss with success upcall: 1 > miss with failed upcall: 331 > avg. packets per output batch: 0.00 > idle cycles: 0 (0.00%) > processing cycles: 19596627706 (100.00%) > avg cycles per packet: 252.96 (19596627706/77470176) > avg processing cycles per packet: 252.96 (19596627706/77470176) > > ### AVX512 Lookup (restart ovs-vswitchd with additional command > "dpif-netdev/subtable-lookup-set avx512_gather 5" > pmd thread numa_id 0 core_id 0: > packets received: 1178784 > packet recirculations: 0 > avg. datapath passes per packet: 1.00 > emc hits: 0 > smc hits: 0 > megaflow hits: 0 > avg. subtable lookups per megaflow hit: 0.00 > miss with success upcall: 13 > miss with failed upcall: 1178739 ---> this looks not right > avg. packets per output batch: 0.00 > idle cycles: 0 (0.00%) > processing cycles: 5408870500 (100.00%) > avg cycles per packet: 4588.52 (5408870500/1178784) > avg processing cycles per packet: 4588.52 (5408870500/1178784) The statistics seem accurate (but indeed the upcall count is unexpected and too high). This aligns with a ukey-install fail as noted in the logs above. This seems to indicate that with the AVX512 lookup the ukey install fails. I'd like to reproduce to investigate - above questions about traffic/rules is hopefully enough to identify. There is an alternative - set the "autovalidator" DPCLS implementation to the highest priority, and it should ovs_assert() if the scalar/AVX512 implementations mismatch. Then a dump of the OVS miniflow will give what's needed to verify root cause. > > > 6) gdb also looks not right..., I didn't see any avx512 instructions <snip> > > Disassembly here shows AVX512 register usage here, as expected. > > OK, tried > (gdb) disas dpcls_avx512_gather_skx_mf_5_1 > and works for me. I can see avx512 instructions. OK Great, good progress again. > > Would you try some of the above and see can it be reproduced? > > btw, I saw every second ovs is doing reprobing > 2020-05-20T14:15:15.113Z|00373|dpif_netdev(pmd-c00/id:9)|INFO|reprobing > sub func, 4 1 > 2020-05-20T14:15:16.129Z|00374|dpif_netdev(pmd-c00/id:9)|INFO|reprobing > sub func, 4 1 Yes this is expected in the v2 of the patchset, and something that will be revised/updated/refactored away in a future version of the patchset - so that the reprobe only occurs when prioritizes are changed. Regards, -Harry _______________________________________________ dev mailing list [email protected] https://mail.openvswitch.org/mailman/listinfo/ovs-dev
