> > 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.
>
btw I have only one OpenFlow rule, 'actions=drop'
The pcap file as input is a random one I just capture in my machine's interface
root@instance-3:~/ovs# tcpdump -n -r p0.pcap  | wc -l
reading from file p0.pcap, link-type EN10MB (Ethernet)
22
root@instance-3:~/ovs# tcpdump -n -r p0.pcap
reading from file p0.pcap, link-type EN10MB (Ethernet)
22:30:10.471943 IP 10.182.0.2.22 > 76.21.95.192.62190: Flags [P.], seq
3532581039:3532581163, ack 2971134033, win 501, options [nop,nop,TS
val 521819346 ecr 304440082], length 124
22:30:10.499759 IP 76.21.95.192.62190 > 10.182.0.2.22: Flags [.], ack
124, win 4092, options [nop,nop,TS val 304440141 ecr 521819346],
length 0
22:30:13.242821 IP 76.21.95.192.62190 > 10.182.0.2.22: Flags [P.], seq
1:37, ack 124, win 4096, options [nop,nop,TS val 304442869 ecr
521819346], length 36
22:30:13.243113 IP 10.182.0.2.22 > 76.21.95.192.62190: Flags [P.], seq
124:160, ack 37, win 501, options [nop,nop,TS val 521822117 ecr
304442869], length 36
22:30:13.271718 IP 76.21.95.192.62190 > 10.182.0.2.22: Flags [.], ack
160, win 4094, options [nop,nop,TS val 304442900 ecr 521822117],
length 0
22:30:13.415212 IP 76.21.95.192.62190 > 10.182.0.2.22: Flags [P.], seq
37:73, ack 160, win 4096, options [nop,nop,TS val 304443043 ecr
521822117], length 36
22:30:13.415479 IP 10.182.0.2.22 > 76.21.95.192.62190: Flags [P.], seq
160:196, ack 73, win 501, options [nop,nop,TS val 521822289 ecr
304443043], length 36
22:30:13.442371 IP 76.21.95.192.62190 > 10.182.0.2.22: Flags [.], ack
196, win 4094, options [nop,nop,TS val 304443069 ecr 521822289],
length 0
22:30:13.577866 IP 76.21.95.192.62190 > 10.182.0.2.22: Flags [P.], seq
73:109, ack 196, win 4096, options [nop,nop,TS val 304443208 ecr
521822289], length 36
22:30:13.578123 IP 10.182.0.2.22 > 76.21.95.192.62190: Flags [P.], seq
196:232, ack 109, win 501, options [nop,nop,TS val 521822452 ecr
304443208], length 36
22:30:13.608249 IP 76.21.95.192.62190 > 10.182.0.2.22: Flags [.], ack
232, win 4094, options [nop,nop,TS val 304443230 ecr 521822452],
length 0
22:30:16.932478 IP 169.254.169.254.80 > 10.182.0.2.51642: Flags [P.],
seq 1150154089:1150154672, ack 1477571123, win 65535, length 583:
HTTP: HTTP/1.1 200 OK
22:30:16.932540 IP 10.182.0.2.51642 > 169.254.169.254.80: Flags [.],
ack 583, win 64737, length 0
22:30:16.932547 IP 169.254.169.254.80 > 10.182.0.2.51642: Flags [F.],
seq 583, ack 1, win 65535, length 0
22:30:16.933193 IP 10.182.0.2.51642 > 169.254.169.254.80: Flags [F.],
seq 1, ack 584, win 64736, length 0
22:30:16.933280 IP 169.254.169.254.80 > 10.182.0.2.51642: Flags [.],
ack 2, win 65535, length 0
22:30:16.936976 IP 10.182.0.2.51650 > 169.254.169.254.80: Flags [S],
seq 1944213115, win 65320, options [mss 1420,sackOK,TS val 2204263930
ecr 0,nop,wscale 7], length 0
22:30:16.937201 IP 169.254.169.254.80 > 10.182.0.2.51650: Flags [S.],
seq 4118061879, ack 1944213116, win 65535, options [mss 1420,eol],
length 0
22:30:16.937234 IP 10.182.0.2.51650 > 169.254.169.254.80: Flags [.],
ack 1, win 65320, length 0
22:30:16.937297 IP 10.182.0.2.51650 > 169.254.169.254.80: Flags [P.],
seq 1:287, ack 1, win 65320, length 286: HTTP: GET
/computeMetadata/v1/instance/network-interfaces/?alt=json&last_etag=7c556bc02e6331f4&recursive=True&timeout_sec=72&wait_for_change=True
HTTP/1.1
22:30:16.937374 IP 169.254.169.254.80 > 10.182.0.2.51650: Flags [.],
ack 287, win 65249, length 0
22:30:16.937428 IP 169.254.169.254.80 > 10.182.0.2.51650: Flags [.],
ack 287, win 65535, length 0

I also attached the pcap file.
https://drive.google.com/file/d/1CR5pMebrtjzShF9bpXJcr9GAQY_6Og44/view?usp=sharing

> > 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?
>
describe in comment above.

>
> > > > 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?
Yes.
before setting avx512:
root@instance-3:~/ovs# ovs-appctl dpif-netdev/pmd-stats-show
pmd thread numa_id 0 core_id 0:
  packets received: 70630720
  packet recirculations: 0
  avg. datapath passes per packet: 1.00
  emc hits: 64206054
  smc hits: 0
  megaflow hits: 6424309
  avg. subtable lookups per megaflow hit: 1.00
  miss with success upcall: 1
  miss with failed upcall: 324
  avg. packets per output batch: 0.00
  idle cycles: 1668002 (0.01%)
  processing cycles: 17710219822 (99.99%)
  avg cycles per packet: 250.77 (17711887824/70630720)
  avg processing cycles per packet: 250.74 (17710219822/70630720)


> > > 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.

Why ukey is related here? Does you avx512 patch make any change to ukey?

>
> 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.
>
that's a cool feature.
When setting
ovs-appctl dpif-netdev/subtable-lookup-set autovalidator 100
log shows
2020-05-21T22:28:55.964Z|77007|dpif_lookup_autovalidator(pmd-c00/id:9)|ERR|matches_good
7 != matches_test 0 for func avx512_gather
2020-05-21T22:28:55.964Z|77008|dpif_lookup_autovalidator(pmd-c00/id:9)|ERR|matches_good
7 != matches_test 0 for func avx512_gather
2020-05-21T22:28:55.965Z|77009|dpif_lookup_autovalidator(pmd-c00/id:9)|ERR|matches_good
3 != matches_test 0 for func avx512_gather
2020-05-21T22:28:55.965Z|77010|dpif_lookup_autovalidator(pmd-c00/id:9)|ERR|matches_good
15 != matches_test 0 for func avx512_gather

Thanks
William
_______________________________________________
dev mailing list
[email protected]
https://mail.openvswitch.org/mailman/listinfo/ovs-dev

Reply via email to