| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2020-07-17 | |||
| 02:04:58 | sean-k-mooney | melwitt: it is | |
| 02:05:10 | sean-k-mooney | but there is a 3 minitu gap betwen it starting and finishing | |
| 02:05:14 | melwitt | I know, just replying super late | |
| 02:05:43 | mnaser | i see a bunch of this: `ovs_rcu(urcu5)|WARN|blocked 1000 ms waiting for main to quiesce` | |
| 02:06:29 | sean-k-mooney | mnaser: in the vswitchd log you should seee somthign like this | |
| 02:06:31 | sean-k-mooney | 2020-05-06T19:52:07.865Z|00031|bridge|INFO|bridge br-int: added interface tap36660a66-00 on port 3 | |
| 02:06:50 | mnaser | ah, yes | |
| 02:07:37 | sean-k-mooney | i think you are looking for tap66278068-75 | |
| 02:07:39 | mnaser | 2020-07-16T21:37:25.283Z|11608|bridge|INFO|bridge br-int: added interface qvo66278068-75 on port 32307 | |
| 02:08:01 | sean-k-mooney | ah you are using iptables | |
| 02:08:23 | sean-k-mooney | not the contrack security group driver? | |
| 02:08:29 | mnaser | yes, there's a plan to move towards openvswitch driver | |
| 02:08:35 | mnaser | iptables_hybrid right now | |
| 02:08:56 | sean-k-mooney | yep that is why the interface name is diffrent | |
| 02:09:52 | sean-k-mooney | given it started plugging at 21:34:21.726 | |
| 02:09:56 | sean-k-mooney | that took a while | |
| 02:10:53 | sean-k-mooney | plugging finished at 21:37:49.943 | |
| 02:11:20 | sean-k-mooney | there is still a 24 second gap but that is more resonably | |
| 02:11:29 | mnaser | so either: nova is 'distracted' doing something else and not actually running ovs-vsctl commands? | |
| 02:11:41 | mnaser | or the ovs-vsctl command is actually taking 3 minutes | |
| 02:12:27 | sean-k-mooney | it could be that its in the queue of peneding funciton to execute in privsep for a while too | |
| 02:13:00 | mnaser | that's very likely because | |
| 02:13:13 | mnaser | https://www.irccloud.com/pastebin/hv0DDE8m/ | |
| 02:13:20 | mnaser | 25% cpu usage for privsep sounds off | |
| 02:14:04 | sean-k-mooney | i dont know didnt you say your creating 250 port/vms at the same time | |
| 02:14:28 | sean-k-mooney | but i think stein predates privsep multi threading | |
| 02:14:58 | mnaser | i mean, they're not all 250 ports there, but i've seen a case of 15 vms spawning at teh same time here | |
| 02:15:14 | mnaser | so 15 vms * 5 ports each = 75 ports being attached together at elast | |
| 02:18:06 | sean-k-mooney | so there are a few things you could try | |
| 02:18:35 | sean-k-mooney | if i am remeberign correctly the native ovsdb interface in os-vif does not use privsep | |
| 02:19:17 | mnaser | https://docs.openstack.org/releasenotes/oslo.privsep/stein.html -- "Privsep now uses multithreading to allow concurrency in executing privileged commands. The number of concurrent threads defaults to the available CPU cores, but can be adjusted by the new thread_pool_size config option." | |
| 02:20:11 | mnaser | and i have privsep 1.32.1 -- cool, so that's taken care of -- i think moving to native ovsdb is probably much better/cleaner | |
| 02:20:38 | sean-k-mooney | you can set ovsdb_interface="native" in the nova.conf | |
| 02:20:43 | sean-k-mooney | but im just checkign the group | |
| 02:21:30 | sean-k-mooney | i think its somthign like vif_plug_ovs but give me a sec | |
| 02:21:37 | sean-k-mooney | i also need to chagne the default on master | |
| 02:21:53 | mnaser | sean-k-mooney: https://github.com/openstack/os-vif/blob/d588708f2149b4503e63a2c2165201c9fe399bdb/vif_plug_ovs/tests/functional/ovsdb/test_ovsdb_lib.py#L54 tests show os_vif_ovs | |
| 02:22:27 | sean-k-mooney | ah yes [os_vif_ovs] | |
| 02:23:10 | mnaser | ok, setting to native | |
| 02:23:34 | mnaser | the plugs that happen on start up were also not very fast, taking ~5s each | |
| 02:23:44 | mnaser | perhaps this will show difference | |
| 02:24:11 | mnaser | 2020-07-17 02:23:44.773 1550960 DEBUG ovsdbapp.backend.ovs_idl.vlog [-] tcp:127.0.0.1:6640: entering ACTIVE _transition /openstack/venvs/nova-19.0.8/lib/python2.7/site-packages/ovs/reconnect.py:485 | |
| 02:24:13 | sean-k-mooney | ah this is is where that gets generateed https://github.com/openstack/os-vif/blob/master/os_vif/plugin.py#L79 | |
| 02:24:51 | sean-k-mooney | mnaser: that looks like its connect with the native backend alright | |
| 02:25:10 | mnaser | yeah but nova-compute is pegged at 100% cpu now on start up | |
| 02:25:14 | mnaser | time to see what its doing | |
| 02:25:29 | sean-k-mooney | well it does a lot | |
| 02:25:39 | sean-k-mooney | including pluging all the port of every vm on the host | |
| 02:25:59 | sean-k-mooney | but its going to run all the reousce tracker stuff before that form init_host | |
| 02:26:20 | mnaser | just sent USR2 | |
| 02:26:46 | sean-k-mooney | it that the guru meditation report | |
| 02:27:20 | mnaser | yeah | |
| 02:27:36 | sean-k-mooney | ya i have no idea how to read those | |
| 02:27:54 | mnaser | oddly enough though, its still taking 5 seconds to plug a port on start up | |
| 02:28:27 | sean-k-mooney | has the privsep load dropped | |
| 02:29:22 | sean-k-mooney | i dont know if ovsdbapp uses privsep internaly but os-vif nolonger need to use prvisep for the ovs db updates at least | |
| 02:29:27 | mnaser | oooou i have an idea | |
| 02:29:37 | mnaser | i think ipv6 being enabled is hurting this host | |
| 02:29:46 | sean-k-mooney | it still needs privsep for other thngs | |
| 02:29:53 | sean-k-mooney | oh hum | |
| 02:29:53 | mnaser | seems like it was stuck on /openstack/venvs/nova-19.0.8/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:649 in _check_my_ip | |
| 02:29:57 | mnaser | on start up | |
| 02:30:02 | mnaser | im going to time that | |
| 02:30:11 | sean-k-mooney | ya maybe | |
| 02:30:16 | mnaser | specifically `ips = compute_utils.get_machine_ips()` | |
| 02:30:28 | mnaser | yep, just ran that and its eating up a lot of cpu time | |
| 02:30:34 | sean-k-mooney | that might be trying to do a revers dns lookup | |
| 02:31:24 | mnaser | # ip addr | grep inet | wc -l => 746 | |
| 02:31:40 | sean-k-mooney | am im going to have to call it a night but ill be around in a coule of hour. | |
| 02:31:46 | sean-k-mooney | oh all the link local addresses | |
| 02:31:51 | sean-k-mooney | on all the tap devices | |
| 02:32:10 | sean-k-mooney | mnaser: artom saw an issue with this before | |
| 02:32:17 | mnaser | len(netifaces.interfaces()) => 973 | |
| 02:32:26 | mnaser | yeah, i think i'm onto something here | |
| 02:32:28 | sean-k-mooney | i think he fixed it but maybe not on master | |
| 02:32:33 | sean-k-mooney | * stien | |
| 02:32:44 | sean-k-mooney | maybe we didnt backport it | |
| 02:34:40 | mnaser | t = time.time(); netifaces.ifaddresses('qvo64d61663-06'); print(time.time() - t) => 133ms | |
| 02:35:02 | mnaser | 973*133ms = 129s | |
| 02:35:48 | sean-k-mooney | https://review.opendev.org/#/c/672161/ | |
| 02:35:51 | mnaser | we should probably just skip qbr/qvo/qvb/tap in there | |
| 02:36:20 | sean-k-mooney | ya proably | |
| 02:36:46 | sean-k-mooney | so artom moved it to init_host to fix https://bugs.launchpad.net/nova/+bug/1837075 | |
| 02:36:46 | openstack | Launchpad bug 1837075 in OpenStack Compute (nova) stein "Evacuation takes too long when destination host has a large number of NICs" [Low,Fix committed] - Assigned to Artom Lifshitz (notartom) | |
| 02:36:59 | mnaser | but instead it takes a long time to init_host :) | |
| 02:37:28 | sean-k-mooney | yes but we used to call it at runtime several times | |
| 02:37:37 | sean-k-mooney | so we look it up once now and cache it | |
| 02:38:24 | sean-k-mooney | we used to call it every time we called get_host_ip_addr | |
| 02:38:31 | sean-k-mooney | which we did for all move operations | |
| 02:38:31 | mnaser | yeah, perhaps that function could use skipping nova-managed devices | |
| 02:39:00 | sean-k-mooney | this is all its used for | |
| 02:39:02 | sean-k-mooney | ips = compute_utils.get_machine_ips() | |
| 02:39:04 | sean-k-mooney | if CONF.my_ip not in ips: | |
| 02:39:06 | sean-k-mooney | LOG.warning('my_ip address (%(my_ip)s) was not found on ' | |
| 02:39:08 | sean-k-mooney | 'any of the interfaces: %(ifaces)s', | |
| 02:39:10 | sean-k-mooney | {'my_ip': CONF.my_ip, 'ifaces': ", ".join(ips)}) | |
| 02:39:19 | sean-k-mooney | it validating that the ip we set in the config if its set is on the host | |
| 02:39:29 | sean-k-mooney | there is proably a better way to do that | |
| 02:40:36 | mnaser | yeah i cant find a better thing but i think skipping qbr/qvo/qvb/tap might speed it up.. a lot | |
| 02:40:56 | sean-k-mooney | where you debuging startup latency | |