Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-08-06
13:38:18 efried yes. I understand they've been having a tough time with... follow through from... previously committed resources...
13:38:26 sean-k-mooney i only have a 3 day week this week but im hoping to be able to try out some of this in the next week or two
13:38:32 mriedem hmm, i think set_update_time_on_success isn't using what it once did (RequestSpec vs HostState)
13:39:07 mriedem oh nvm
13:39:42 sean-k-mooney efried: well it does look like at least in the last week or so that progess has been picking up a bit
13:40:36 sean-k-mooney i need to try and review more of this work but i also need to review gibi port migrtion stuff so time is a factor.
13:41:15 mriedem cdent: i think the "older computes" comment is from when edleafe wrote this https://review.opendev.org/#/c/160511/ back in kilo :)
13:49:03 mriedem cdent: but yeah i suppose we have to hit that method to get the host mapping at least once per host to determine which cell the host is in so we know where to pull the instances from (which cell db), so in your test with 25 fake computes the profiler shows that method was called 25 times
13:49:04 cdent mriedem: the patch prior to my last one there shows how to do profiling in an eventlet situation, in case you want to try it elsewhere
13:49:30 mriedem yup i saw, thanks. that would be useful with something like this god awful mess https://review.opendev.org/#/c/674422/
13:49:34 cdent (I tried to do 100 fake computes and my compute explored)
13:50:04 cdent exploded even
13:50:05 mriedem i don't think i've been able to go over 30 fake computes in a devstack with 8GB RAM and 8 VCPU
13:50:13 mriedem and 1 API_WORKER per service
13:50:59 cdent I think I could probably make 50, I'm pretty smooth at 25 with 16GB,16vcpu
13:51:23 mriedem you know, i'd give a scratch n sniff sticker if someone threw up a small doc about how to do profiling like this in nova somewhere in https://docs.openstack.org/nova/latest/contributor/#testing
13:51:44 cdent I think I could do that, but it would really depend on the smell
13:52:13 efried gibi, melwitt: Y'all okay if I continue working on the series at https://review.opendev.org/#/c/524306/ ?
13:54:07 gibi efried: it is OK for me. I can keep reviewing the patches.
13:54:16 efried gibi: I'd be fixing the func failures, either in your poison patch or by slotting another one underneath. And melwitt I'd be addressing gibi's comment on the bottom by removing that fixture.
13:54:41 efried gibi: You think the ComputeDriver.get_available_resource signature change is worth doing?
13:56:22 gibi efried: I need a refresh why we started this series in the first place. What is wrong with generating a new context. I got involved into it due to the testing impact of it
13:56:53 dustinc efried: good point thanks
13:57:13 efried gibi: I'm not completely sure why the series was *started*, but I can tell you why I got involved.
13:58:10 gibi efried: I'm going to dig into the past to see the reason..
13:58:14 efried gibi: The global_request_id we're logging is coming from whatever RequestContext is in oslo.context's thread local store, which is *not* the same context we're using to pass the X-Openstack-Request-Id header around to other services like Placement.
13:58:33 efried which means that, without additional hacking, we can't actually follow the request from e.g. n-cpu to placement
13:58:38 efried which was the whole point of global_request_id in the first place.
13:58:50 gibi efried: thanks, that seems to be a worthy cause
13:59:00 efried So I've been trying to track down how that whole mechanism works and how we can get it so you can actually grep logs for a request ID and see the flow of an operation.
13:59:36 efried gibi: My latest attempt actually diverged from that series a little bit: https://review.opendev.org/#/c/674138/
13:59:41 gibi is there any alternative to passing the context to the ComputeDriver.get_available_resource ?
14:00:42 efried To avoid having that one libvirt method call get_admin_context? Yes, melwitt and I talked about storing the context on, like, the compute manager object and accessing it from the virt driver via the virtapi.
14:00:55 efried Questionable which is a worse hack, really.
14:01:13 gibi I see
14:01:13 efried Having it as a param to get_available_resource seems appropriate from a zoomed-out perspective
14:01:18 efried but it's a fairly intrusive change as you can see.
14:01:26 efried but
14:01:27 gibi yepp
14:01:42 efried that's assuming we need to be putting restrictions on get[_admin]_context like this at all.
14:02:02 efried which, if we're doing that more carefully, we might not need to bother with
14:02:40 mriedem cdent: typically root beer and grape are all i offer
14:03:14 efried gibi: https://review.opendev.org/#/c/674138/ operates on the theory that get[_admin]_context should be able to be used wherever, and should (still) not overwrite the thread local store, as long as we're careful about where we *do* overwrite, and as long as we set global_request_id properly/carefully in the right places.
14:04:07 efried so what I did was essentially make overwrite=False the default, and then made sure we're always setting a global_request_id in whatever RequestContext we're using.
14:04:09 gibi efried: I think I like your current ^^ approach than the restriction of get[_admin]_context
14:04:52 efried I need to go poke through the logs and see whether/how it worked. Like, see if a live migration operation gets logged properly throughout all the hosts.
14:05:28 efried btw, on that note, the nova-live-migration job seems to produce only one n-cpu log. Is it the consolidated log from both "nodes"?
14:05:34 gibi I feel there are smaller amount of places where we need to generate new global_request_id than the number of places we call for a new context
14:05:40 efried ++
14:06:34 gibi efried: there is a subnode-2 folder in the logs
14:06:43 gibi with another n-cpu logs
14:06:47 efried ah!
14:06:51 efried Thanks
14:07:26 gibi so in summary If your approach works then I'm OK to abbandon the old series
14:09:21 efried gibi: I'm sure there's still more to do. This is not a simple thing.
14:09:57 efried glancing at the n-api log, my initial thought is that the global_request_id is being persisted too long.
14:10:12 efried I think what we probably want to do is change it any time we get a new incoming API request.
14:11:00 efried As yet, I have no idea where in the code would be a good place to do that...
14:15:36 gibi efried: does this in connection with the fact that periodic tasks also needs a context / global_request_id but they are not triggered by a specific API request?
14:19:55 efried gibi: Yup, that's an issue as well.
14:20:19 efried I'm not sure whether periodics ought to have one global_request_id forever, or if they should get a new one every time they trigger.
14:21:01 efried but I'm *pretty* sure they shouldn't share a global_request_id with any actual operations from an API request
14:23:24 cdent efried: new one each job would be most useful when grepping (or otherwise searching)
14:23:42 efried cdent: "job", are you talking about periodics or API requests?
14:23:48 cdent periodics
14:24:25 efried Okay. Meanwhile cdent I could probably use your wsgi skills here...
14:24:44 efried can you help me find where nova does that middleware thing with the request_id?
14:24:55 cdent yeah, one sec
14:26:09 efried actually, I don't think that's what I want.
14:26:14 efried Cause that part is working
14:26:43 efried problem right now is, that req ID is persisting way too long in the API thread.
14:26:55 cdent efried: nova/api/compute_req_id.py has a subclass of oslo_middleware.request_id.RequestId
14:27:14 efried Yeah, that's setting the header inbound & outbound, which is working.
14:27:22 efried sorry, inbound only
14:27:25 cdent efried: is it possible that tempest is _sending_ it
14:28:52 efried cdent: looks like not.
14:29:00 efried which is actually fine for now
14:29:13 cdent efried: i haven't got enough context loaded in at the moment
14:29:25 efried actually if tempest *were* sending it, I wouldn't be seeing the behavior I'm seeing
14:29:36 efried cdent: So what I'm looking for is this:
14:29:45 efried Presumably the API server sits there waiting for requests
14:29:56 efried when a request comes in, it... spawns? reuses? a thread to handle it
14:30:21 efried Whatever RequestContext that thread gets needs to get a fresh global_request_id
14:30:31 efried early as possible
14:30:59 efried so - I need to grab hold of the code that spins off that thread
14:31:39 efried (btw, ^ is for API requests obvi. Periodics will be a separate thing entirely.)
14:33:01 mriedem https://github.com/openstack/nova/blob/master/nova/api/openstack/auth.py#L57 is what creates the RequestContext in the compute API
14:35:21 efried mriedem: yup https://review.opendev.org/#/c/674138/4/nova/api/openstack/auth.py
14:35:41 efried So that's working now
14:35:57 efried the thing I'm trying to tackle now is, I want each API request to get a new global_request_id.
14:36:16 efried because right now it's getting reused for multiple operations
14:36:33 efried Actually, cdent, I think perhaps that compute_req_id might be the place to do it.
14:36:59 efried The superclass is pulling in a request ID from headers if available... but what I can do is *set* a new one if there wasn't one in the header.
14:43:20 openstackgerrit Eric Fried proposed openstack/nova master: WIP: Always set a global_request_id in RequestContext https://review.opendev.org/674138
14:43:22 openstackgerrit Eric Fried proposed openstack/nova master: WIP: Correct global_request_id sent to Placement https://review.opendev.org/674129
14:43:36 efried cdent, mriedem: let's see how that shakes out ^
14:46:23 openstackgerrit Matt Riedemann proposed openstack/nova master: Replace non-nova server fault message https://review.opendev.org/674821
14:46:34 mriedem dansmith: ^
14:46:47 fungi i'm watching these go up too, thanks mriedem!
14:47:07 dansmith mriedem: ack

Earlier   Later