| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-08-14 | |||
| 19:51:36 | smcginnis | Volume created and attached with Ocata, then after it upgrades and tries to detach in Pike it fails. | |
| 19:51:55 | smcginnis | Nova tells cinder to begin_detaching, which places the volume status in "detaching" | |
| 19:52:08 | smcginnis | Then never makes it back to Cinder to do the actual detach. | |
| 19:52:23 | smcginnis | And grenade ends up timing out waiting for the volume state to go from detaching to available. | |
| 19:52:53 | dansmith | smcginnis: link? | |
| 19:53:30 | smcginnis | dansmith: Sorry, gotta find my tabs now. Looking... | |
| 19:53:52 | smcginnis | dansmith: Here is the grenade log. | |
| 19:53:54 | smcginnis | 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 | |
| 19:54:35 | smcginnis | Last item here is a call to servers with a DELETE on os-volume_attachments: | |
| 19:54:38 | smcginnis | http://logs.openstack.org/57/493057/10/check/gate-grenade-dsvm-neutron-multinode-ubuntu-xenial/3004b34/logs/new/screen-n-api.txt.gz | |
| 19:54:42 | smcginnis | But nothing ever makes it down to Cinder. | |
| 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 | dansmith | which seems weird if we're journald the whole time | |
| 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: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 :) | |