Earlier  
Posted Nick Remark
#openstack-nova - 2017-08-14
19:54:56 smcginnis jgriffith, ildikov: Feel free to add more findings ^^
19:55:55 jgriffith smcginnis seems like a good enough summary; just to note that that volume_attachments is the nova route table entry, NOT Cinder attachments API
19:56:08 jgriffith that call goes; and nothing is ever actually issued to cinder, cinderclient etc
19:56:21 jgriffith at least not that I could find
19:56:49 ildikov good summary
19:57:29 oomichi toabctl: thanks, but need to update https://review.openstack.org/#/c/398308 again
19:57:59 dansmith smcginnis: so it looks like that delete call is later than the latest thing in n-cpu.log
19:58:21 dansmith the detach happens on the compute, IIRC
19:58:46 smcginnis dansmith: Check under /new
19:59:26 dansmith not much evidence of anything happening under new
20:00:41 dansmith the begin_detach happens on the api node, but the rest happens on compute
20:01:16 smcginnis dansmith: It is multinode. Not sure how that ends up in the n-cpu logs.
20:01:25 dansmith yeah I know, but
20:01:36 dansmith the new/n-cpu.log has hardly anything in it
20:02:03 openstackgerrit melanie witt proposed openstack/nova master: doc: Extend nfv feature matrix with pinning/NUMA https://review.openstack.org/327126
20:04:43 dansmith smcginnis: so the change in play here is just something against grenade right?
20:05:32 dansmith oh this is that other stack of things
20:07:36 smcginnis dansmith: Yeah, all that.
20:08:36 dansmith why are all the log files mangled with unparsed ansi?
20:08:49 dansmith and is this trying to go from pike->master or from ocata->master?
20:10:35 openstackgerrit Thomas Bechtold proposed openstack/nova master: Handle deleted instances when refreshing the info_cache https://review.openstack.org/398308
20:10:40 toabctl oomichi, done
20:13:01 oomichi toabctl: thanks, +2
20:14:39 smcginnis dansmith: I believe it's ocata>pike.
20:14:51 smcginnis dansmith: Yeah, not sure what's up with the log formatting, but it's annoying.
20:15:14 dansmith smcginnis: well, I'm just wondering if it's related.. I'm not used to seeing log files in all the places where they appear in this
20:15:36 dansmith but it definitely seems like nova-compute isn't running when this happens, or isn't listening on the right mq or something
20:18:08 smcginnis dansmith: I wonder who would know if that's normal. -qa? I hadn't noticed it before this patch either.
20:18:34 dansmith I would ask sdague, but he's on vacay for two weeks
20:18:44 dansmith mtreinish might know
20:18:47 dansmith or clarkb
20:19:08 clarkb ?
20:19:16 dansmith smcginnis: what's the point of all the patches in front of this? the one from dims has no detail
20:19:28 dansmith clarkb: we're looking at a grenade job with a weird (to me) log file layout
20:19:35 dansmith http://logs.openstack.org/57/493057/10/check/gate-grenade-dsvm-neutron-multinode-ubuntu-xenial/3004b34/logs/
20:20:03 dansmith clarkb: where we have logs at the top, and new/ and old/, and new/ has some like n-cpu logs, but for a hot minute.. basically only a gmr dump
20:20:21 dansmith clarkb: is that a recent change?
20:20:36 clarkb was this a pike -> master upgrade?
20:20:39 dansmith smcginnis: by the one from dims, I mean the one that sets conductor mode
20:20:46 dansmith clarkb: smcginnis says ocata->pike
20:21:21 smcginnis dansmith: I'm not sure on the conductor one.
20:21:39 smcginnis dansmith: But we had to do the NO_WSGI to get things even remotely working for now.
20:21:41 dims dansmith : so, ttx filed https://review.openstack.org/#/c/493057/, it did not work as-is, so i started digging in trying to "fix" things to work
20:21:52 dansmith smcginnis: well, that's the one I'd suspect for being most related to this
20:21:59 smcginnis Not sure if that's actually supported to go from non-wsgi to uwsgi in grenade.
20:22:03 clarkb dansmith: smcginnis it was pike -> master
20:22:06 clarkb http://logs.openstack.org/57/493057/10/check/gate-grenade-dsvm-neutron-multinode-ubuntu-xenial/3004b34/logs/devstack-gate-setup-workspace-old.txt.gz#_2017-08-14_16_33_08_300
20:22:13 dims y pike to master
20:22:15 clarkb so the reason the logs are weird is the journald switch
20:22:30 clarkb so now on the old side (pike) and new side (master/queens) we use journald for logs
20:22:37 smcginnis clarkb: Oh, oops. Sorry, you are right, pike-master.
20:22:54 dims dansmith : pick any of the "Depends-On" and i can try to answer from my ntoes
20:23:08 dansmith clarkb: on the old and new side we use journald? you said a second ago "the journald switch"
20:23:16 clarkb so we likely just need to cleanup things to accomodate that (so you don't see old/ and new/ screen-* logs anymore, just the top level log
20:23:19 dansmith dims: the conductor mode one
20:23:28 dansmith okay
20:23:30 dims this one? https://review.openstack.org/#/c/493380/6/grenade.sh
20:23:41 clarkb dansmith: yes we started using journald in pike so now that the upgrade is pike -> queens we use journald for the entire thing
20:23:51 dansmith dims: yes and specifically the CELLSV2_SETUP one
20:23:52 clarkb dansmith: so the top level log files should contain old and new logs
20:24:11 clarkb I do not know why we see things in the new/ logs but guessing thats output from grenade ending up in files that can be cleaned up?
20:24:21 dansmith clarkb: okay
20:24:27 dansmith clarkb: it's output from nova-cpu actually
20:24:41 dims CELLSV2_SETUP was defaulting to superconductor and i ran into the problem with "No hosts found to map to cell, exiting."
20:24:41 dansmith which seems weird if we're journald the whole time
20:25:07 clarkb dansmith: you know grenade may not know to restart them using systemd yet
20:25:12 clarkb maybe?
20:25:36 dansmith clarkb: so it's not restarting services at all you mean?
20:25:50 dansmith dims: okay I guess if we start on pike we need that earlier than we have it now
20:25:52 dims dansmith : then i had to add NOVA_USE_MOD_WSGI CINDER_USE_MOD_WSGI to False to avoid switching from one to another between base and target
20:26:06 clarkb dansmith: or its doing it "manuall" and not starting the service with systemd? I need to dig into logs more to see
20:26:31 dims dansmith : happy to clear all my experiments and start over :)
20:26:53 dansmith dims: no, it makes sense now that I know we're going pike->master I think
20:26:59 dansmith just hadn't thought about that yet
20:27:10 dims understood
20:27:19 mtreinish clarkb: oh, this is the thing we were predicting would happen a while ago about the split between old and new
20:27:25 mtreinish and not being clear
20:27:39 dims so i got it past the base devstack and then upgrade and then bringing up all the services with those 3 patches
20:27:55 dims now failing with cinder volume not getting detached
20:28:18 dims we can see the os-detach happening in the c-api, but no logs in c-sch or c-vol
20:28:31 clarkb mtreinish: ya
20:28:40 clarkb dansmith: reading logs I think it uses systemd on both sides
20:28:45 mtreinish dims: do you have a link to the log output?
20:28:53 smcginnis Well, we see the begin_detach happening in c-api, but then Cinder is never called after that.
20:28:59 clarkb dansmith: you can grep for systemctl start destack@n-cpu.service and you get two instances of it
20:29:07 dims mtreinish : sure http://logs.openstack.org/57/493057/10/check/gate-grenade-dsvm-neutron-multinode-ubuntu-xenial/3004b34/logs/grenade.sh.txt.gz#_2017-08-14_17_21_46_226
20:29:41 dansmith smcginnis: because either n-cpu is not running, or it's not on the right mq bus
20:30:08 smcginnis dansmith: So might still just be a devstack setup issue?
20:30:29 dansmith smcginnis: all you're changing is setup, so it's clearly a setup issue :)
20:30:47 dims dansmith : mtreinish : you can see "Begin detaching volume completed successfully." in the new/screen-c-api.txt grep for "req-2e9c3e74-be5f-4d52-8ac9-878da1b6836e"
20:30:55 dansmith right
20:31:07 smcginnis dansmith: Fair point. ;)
20:31:20 dansmith the next thing after begin is an rpc cast down to the compute
20:31:25 dansmith which never seems to make it
20:31:55 dims aha dansmith
20:33:03 smcginnis dansmith: Which leads to what you were saying of n-cpu being down or on the wrong bus.
20:33:13 dansmith yes
20:33:35 dansmith and that we see no evidence of n-cpu activity around the time that is happening, in any of the scattered logs
20:33:46 dims dansmith : which nova process picks it up?
20:34:02 mtreinish dims: I'm more concerned with it doesn't seem to be starting the services up again. All I see is systemd logging the service stop, not the start up again

Earlier   Later