Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2022-04-28
18:17:25 opendevreview Elod Illes proposed openstack/nova stable/yoga: [CI] Install dependencies for docs target https://review.opendev.org/c/openstack/nova/+/839809
18:22:21 opendevreview Elod Illes proposed openstack/nova stable/xena: [CI] Install dependencies for docs target https://review.opendev.org/c/openstack/nova/+/839810
18:23:42 opendevreview Elod Illes proposed openstack/nova stable/wallaby: [CI] Install dependencies for docs target https://review.opendev.org/c/openstack/nova/+/839811
18:25:32 opendevreview Elod Illes proposed openstack/nova stable/victoria: [CI] Install dependencies for docs target https://review.opendev.org/c/openstack/nova/+/839812
18:26:42 opendevreview Elod Illes proposed openstack/nova stable/ussuri: [CI] Install dependencies for docs target https://review.opendev.org/c/openstack/nova/+/839813
19:06:43 melwitt dansmith: yoga fix for docs job is ready https://review.opendev.org/c/openstack/nova/+/839809
19:07:19 dansmith melwitt: I'm going to go out on a limb and say it'd be okay for you to slam those mofos in :)
19:07:40 dansmith you know, IMHO :D
19:08:06 sean-k-mooney i certenly would not object
19:11:15 melwitt haha ok
21:37:26 opendevreview Dan Smith proposed openstack/nova master: DNM: Run against performance.json patch https://review.opendev.org/c/openstack/nova/+/838934
22:11:42 dansmith clarkb: around?
22:15:17 clarkb dansmith: hi
22:15:44 dansmith not even a full devstack run and 57k queries to the keystone db.. seems high, no?
22:16:16 clarkb dansmith: that does seem high. But openstackclient does have to get a new token for everything since there is no token caching
22:16:18 clarkb perhaps related to that?
22:16:30 dansmith still, 57k
22:16:39 dansmith also, they're almost all select
22:16:47 dansmith don't we have to insert when we create a token?
22:16:51 clarkb yes I think so
22:17:24 dansmith https://termbin.com/s2xj
22:17:26 clarkb I wonder if we need to instrument keystoen directly to try and identify that?
22:17:44 dansmith I think I'd like to know, cause that seems like some n^2 stuff to me
22:17:46 clarkb all of the other services look pretty reasonable
22:17:51 dansmith yes
22:17:56 dansmith neutron is pretty high,
22:18:14 dansmith and I see the number climb pretty fast when it's creating our network and subnet, which seems weird,
22:18:22 dansmith but it's still not 57k-level concerning
22:18:44 clarkb the token issuance would've been my first guess but I agree that those should be writes not reads
22:18:50 dansmith I would think
22:18:53 clarkb and even then we don't do 57k osc commands
22:18:55 clarkb like maybe 1k
22:18:57 dansmith right
22:19:30 clarkb I guess every other api request wiht a keystone token may have to validate with keystone?
22:19:44 clarkb but napkin math adding everything else together there doens't come close to 57k
22:20:13 dansmith yes, I expect validates to turn into selects, but still seems crazy high
22:20:47 dansmith 113 inserts, so maybe say 100 of those are tokens
22:21:09 dansmith that is 570 validates for each one
22:21:30 dansmith I guess catalog lookups maybe
22:21:48 dansmith but still, production systems must be getting _hammered)
22:21:58 clarkb it definitely seems like identifying the source of those and either reducingthem or making them more performant would be a worthwhile exercise
22:22:53 dansmith yeah curious to see if the keystone people think that's crazy or not
22:24:44 dansmith clarkb: check this: https://zuul.opendev.org/t/openstack/build/f31b8439b6dc47a19f9c99bbe3653d74/log/controller/logs/devstacklog.txt#20158
22:24:49 dansmith 82k by the end of the devstack run
22:25:10 dansmith no wonder my 100k limit was rolling over on a full tempest run
22:25:27 clarkb wow and that is before tempest runs
22:26:11 dansmith yeah
22:27:32 dansmith like maybe some ORM usage is causing a bunch of lookups each time we pull a token or something
22:27:45 dansmith like 20 queries to pull the catalog entries or something
22:28:29 dansmith dmendiza[m]: I dunno what tz you're in, but are you around?
22:28:45 clarkb dansmith: if you want we can hold a node then you can check the count and check it again 5 minute slater and see if background tasks have a big impact. You can also do things like catalog list and check the delta etc
22:29:01 clarkb though I seem to recall you are good about running local devstack too
22:29:02 dansmith clarkb: it repros locally just fine, but thanks :)
22:29:06 dansmith yeah
22:30:18 dansmith my local run crashed in the middle, which is why I only got to 57k apparently
22:31:50 dansmith it might be cool to have a way to run tempest single-threaded and capture the after-before numbers for each test to see which operations inflate numbers like these
23:12:00 dansmith clarkb: one test into tempest locally and keystone selects increase by 2500
23:14:53 clarkb dansmith: once you track this down every database behind openstack will owe you beers :)
23:15:31 dansmith I'm just surprised, this might be common knowledge, I dunno
23:15:44 dansmith and I'm just telling you because, I dunno, I need a buddy to be surprised with
23:17:26 clarkb I mean I'm surprised too
23:17:38 clarkb that seems pretty excessive to do a lgocial unit of work in an openstack cloud
23:17:39 sean-k-mooney[m] we are using fernet tokens now instead of uuid tokens right?
23:18:18 dansmith sean-k-mooney[m]: are we? I thought that meant we didn't have to actually store them in order to validate
23:18:42 dansmith provider = fernet
23:18:48 sean-k-mooney[m] so i tought we made the switch by default a while ago
23:18:55 dansmith yep ^
23:20:07 sean-k-mooney[m] have you tried deploying just keystone and then makeing a singel token issue request to see what that results in from a db point of view
23:20:49 dansmith no, I'm just watching the numbers during runs and was surprised.. wasn't looking for anything, was just like "this number has too many zeroes"
23:21:03 clarkb even then why do fernet tokens make you think thousnads of db queries per logical cloud action?
23:21:34 dansmith neutron queries are super high too,
23:21:53 dansmith I'm running tempest mostly doing compute tests right now and neutron and keystone are both ~25k selects
23:22:04 dansmith and nova-api is ~2500 for reference
23:22:28 sean-k-mooney[m] clarkb they done i was wonderign if we were sitll using uuid tokens by mistake or something like that
23:22:52 dansmith sean-k-mooney[m]: ah, good thought then.. but config mentions fernet, so I assume..
23:24:53 sean-k-mooney[m] im kind of surpiseed how low placement its in those results
23:25:21 sean-k-mooney[m] for a service that is basicaly a restapi bolted on top a db it does not do much in the db during that run
23:25:53 dansmith sean-k-mooney[m]: that is before a tempest run, so not much for placement to have done yet
23:26:29 sean-k-mooney[m] i assume that keystone is somewhat inflated as presumable devstack is not caching the tokens so every osc call is a new token ectra
23:26:50 dansmith it is, but still, how can it be 80k?
23:27:31 sean-k-mooney[m] it might be interseting to just add a count of osc calls to devstack but ya its very high
23:28:37 dansmith so in my ongoing tempest run, we're testing compute, nova-api has made 3700 select calls, keystone has made 42k so far
23:28:47 dansmith and tempest doesn't get a token for every operation, AFAIK
23:29:03 dansmith (neutron has made 47k btw)
23:37:21 sean-k-mooney[m] that is nuts considering that neutron with ovn which moves some of the state to the ovn db
23:37:38 dansmith ...and considering we're not testing neutron yet, just using it through nova
23:37:38 sean-k-mooney[m] granted ovn is mainly ment to reduce rpc load not db load
23:37:59 dansmith I'm up to 52k for keystone, 80k for neutron
23:38:00 sean-k-mooney[m] there are quite a few warning in the keystone log
23:38:05 sean-k-mooney[m] https://zuul.opendev.org/t/openstack/build/f31b8439b6dc47a19f9c99bbe3653d74/log/controller/logs/screen-keystone.txt?severity=3
23:38:07 dansmith 6k for nova-api
23:38:25 sean-k-mooney[m] looks the initalial account creation
23:39:09 sean-k-mooney[m] but not sure why the default domain and roles cant be found
23:39:21 dansmith before bootstrap is run maybe?
23:40:07 sean-k-mooney[m] maybe but i would have expected us to bring up keystone pretty early in devstack
23:40:30 dansmith it's mid-early
23:40:40 dansmith or, early-mod
23:40:42 dansmith mid
23:41:09 sean-k-mooney[m] anyway my tablet is about to die so ill check back tomorrow
23:41:14 dansmith o/

Earlier   Later