| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-02-08 | |||
| 14:40:30 | cdent | EmilienM: I'm not sure. It would just be useful to be able to figure out what if anything may have impacted what's going on. | |
| 14:40:45 | EmilienM | the major thing is that we switched back to eventlet | |
| 14:42:58 | dansmith | EmilienM: not for n-cpu which is where this problem is, right? | |
| 14:44:03 | EmilienM | dansmith: I'm afraid I don't understand the question. We switched Nova API to not run in WSGI with apache, but run in classic eventlet. What are you asking about nova compute? | |
| 14:44:35 | dansmith | EmilienM: the problem is that nova-compute is not reporting into placement for the subnode right? | |
| 14:44:44 | johnthetubaguy | FWIW, this error log on the first compute node seems odd to me, not sure if thats normal: http://logs.openstack.org/71/430571/1/check/gate-tripleo-ci-centos-7-nonha-multinode/bae4746/logs/var/log/nova/nova-compute.txt.gz#_2017-02-08_06_43_11_488 | |
| 14:44:48 | EmilienM | cdent: in the logs, I see "Placement service credentials do not work." 3 times but not more so I guess it could register at some point? | |
| 14:45:16 | mriedem | johnthetubaguy: http://logs.openstack.org/71/430571/1/check/gate-tripleo-ci-centos-7-nonha-multinode/bae4746/logs/var/log/nova/nova-compute.txt.gz#_2017-02-08_06_43_11_488 is 'normal' | |
| 14:45:23 | mriedem | we should probably drop that down from an error | |
| 14:45:26 | EmilienM | dansmith: the subnode is a single node overcloud, consider it as a all-in-one node | |
| 14:45:40 | cdent | EmilienM: there's no evidence that the placement application has ever been contacted (in the web logs), unless I'm looking at the wrong ones | |
| 14:45:49 | mriedem | johnthetubaguy: https://github.com/openstack/nova/blob/d48aeb5783ea9bd9495eb2e7c67bc587dfd7d85d/nova/compute/manager.py#L6597 | |
| 14:45:56 | EmilienM | dansmith: node1 == undercloud, which is completely another story (and by the way, undercloud can deploy the overcloud fine in OVB jobs, that run Nova / Ironic) | |
| 14:45:57 | dansmith | the passwords in the two nodes for placement look very different | |
| 14:46:19 | EmilienM | dansmith: yeah don't look at subnode1 please | |
| 14:46:27 | dansmith | alright | |
| 14:46:29 | EmilienM | dansmith: that's another instance of nova, that we don't use in this case | |
| 14:46:42 | EmilienM | subnode2 is the only logs we should look today | |
| 14:46:57 | EmilienM | http://logs.openstack.org/71/430571/1/check/gate-tripleo-ci-centos-7-nonha-multinode/bae4746/logs/subnode-2/var/log/nova/ | |
| 14:47:15 | johnthetubaguy | mriedem: OK, I clearly have less understanding of how this works than I thought | |
| 14:47:22 | openstackgerrit | Balazs Gibizer proposed openstack/nova master: Improve assertJsonEqual error reporting https://review.openstack.org/428199 | |
| 14:47:23 | dansmith | oh, I'm not looking at subnode1 | |
| 14:47:28 | dansmith | I'm looking at -2 | |
| 14:47:33 | EmilienM | ok good | |
| 14:47:43 | dansmith | or are you calling the primary node "subnode1" ? | |
| 14:48:21 | EmilienM | so: http://logs.openstack.org/71/430571/1/check/gate-tripleo-ci-centos-7-nonha-multinode/bae4746/logs/var/log/nova/ is the undercloud and please don't look at it we don't care now | |
| 14:48:36 | EmilienM | http://logs.openstack.org/71/430571/1/check/gate-tripleo-ci-centos-7-nonha-multinode/bae4746/logs/subnode-2/var/log/nova/ is overcloud, and we currently can't spawn a VM on it | |
| 14:48:49 | johnthetubaguy | according to placement, its only ever been reached by the scheduler I guess | |
| 14:48:53 | EmilienM | FYI I'm using https://review.openstack.org/#/c/430571/ for testing | |
| 14:49:26 | cdent | johnthetubaguy: yes (I was looking at the main logs when I saw no activity above, not the subnode-2, but subnode-2 is just hearing from the scheduler) | |
| 14:49:41 | johnthetubaguy | I just wish we had more details on why compute isn't able to talk to placement in here: http://logs.openstack.org/71/430571/1/check/gate-tripleo-ci-centos-7-nonha-multinode/bae4746/logs/subnode-2/var/log/nova/nova-compute.txt.gz#_2017-02-08_06_43_28_610 | |
| 14:50:20 | cdent | johnthetubaguy: shortly before that; http://logs.openstack.org/71/430571/1/check/gate-tripleo-ci-centos-7-nonha-multinode/bae4746/logs/subnode-2/var/log/nova/nova-compute.txt.gz#_2017-02-08_06_40_24_634 | |
| 14:50:33 | dansmith | ot | |
| 14:50:42 | dansmith | it is clearly hitting placement because it's getting Unauthorized right? | |
| 14:51:02 | dansmith | which means that the service catalog is working, and that the credentials just aren't right I think | |
| 14:51:16 | dansmith | unless it's hitting placement for the undercloud somehow, but I doubt it | |
| 14:51:34 | cdent | dansmith: where is unauthorized happening? | |
| 14:51:41 | EmilienM | dansmith: our current CI jobs (pin to nova-ocata-3) use the same credentials, and it seems to work. I can give you a link so you can confirm | |
| 14:51:55 | dansmith | cdent: https://github.com/openstack/nova/blob/master/nova/scheduler/client/report.py#L70-L76 | |
| 14:52:02 | dansmith | cdent: that's the message in the logs, yes? | |
| 14:52:03 | johnthetubaguy | EmilienM: it is probably just silently failing | |
| 14:52:25 | johnthetubaguy | EmilienM: would wouldn't notice anything wrong if compute couldn't ever talk to placement until after ocata-3 | |
| 14:52:39 | EmilienM | ok now i'm checking our haproxy config, etc to make sure placement api is reachable | |
| 14:52:50 | dansmith | cdent: placement access log is completely empty on the undercloud? | |
| 14:53:01 | EmilienM | yeah | |
| 14:53:06 | EmilienM | please don't look undercloud for multinode jobs | |
| 14:53:11 | EmilienM | nova is not used to spawn the overcloud | |
| 14:53:14 | johnthetubaguy | dansmith: its odd we don't see 401 in the placement logs, or is that normal? | |
| 14:53:16 | EmilienM | we use nodepool to spawn the subnode2 | |
| 14:53:20 | dansmith | johnthetubaguy: I dunno | |
| 14:53:39 | cdent | ks_exc.Unauthorized means two things | |
| 14:53:43 | EmilienM | if you want to read logs from a real undercloud that spawns an undercloud, please look OVB jobs: https://review.openstack.org/#/c/430571/ | |
| 14:53:46 | mordred | cdent: of course it does | |
| 14:53:48 | johnthetubaguy | I wonder if its not actually got the correct url from the service catalog, or maybe it just can't talk to keystone to get it? | |
| 14:53:55 | cdent | one of them is entirely driven by code, not a response from anything | |
| 14:53:55 | dansmith | johnthetubaguy: placement access log on the undercloud is zero bytes, but we do have a few gets in the overcloud log | |
| 14:53:59 | cdent | mordred: ikr | |
| 14:54:17 | johnthetubaguy | dansmith: looks like they are the scheduler calls that work, yeah | |
| 14:54:31 | johnthetubaguy | dansmith: well the empty list would give us the no-valid host error I think | |
| 14:54:44 | EmilienM | I don't think it can comes from HAproxy because nova-placement-api log file exists, so API was reached | |
| 14:54:58 | EmilienM | it can be in credentials, I'm checking now. | |
| 14:55:10 | dansmith | actually, placement access is not zero bytes, it just looks empty | |
| 14:55:16 | EmilienM | johnthetubaguy: you said you checked in keystone logs, did you see something? | |
| 14:55:32 | johnthetubaguy | EmilienM: I haven't looked there, was looking at placement | |
| 14:55:52 | cdent | EmilienM: I'm pretty sure when apache starts it opens the log file, but only when the wsgi application is requested to, will it write and when it does the error log should get a bunch of oslo config noise | |
| 14:56:23 | EmilienM | cdent: right, and it's used, see http://logs.openstack.org/71/430571/1/check/gate-tripleo-ci-centos-7-nonha-multinode/bae4746/logs/subnode-2/var/log/nova/nova-placement-api.txt.gz#_2017-02-08_06_40_29_306 | |
| 14:56:58 | cdent | too many different log files! ;) | |
| 14:57:07 | mriedem | i second that | |
| 14:57:09 | dansmith | oh jeez | |
| 14:57:12 | dansmith | why are those there? | |
| 14:57:13 | mriedem | i get totally lost in the tripleo logs | |
| 14:57:27 | dansmith | mriedem: and no filtering :/ | |
| 14:57:36 | mriedem | yes no filtering is my other top complaint | |
| 14:57:59 | EmilienM | that's useful feedback, I'll take some actions | |
| 14:58:02 | dansmith | and it's nearly a full system dump, so lots of noise, and some of the files don't have a mimetype that lets them be displayed in a browser | |
| 14:58:06 | johnthetubaguy | dansmith: thats what I meant by it looks like the scheduler can fetch, even though compute can't :S | |
| 14:58:15 | cdent | so, that log starts at 06:40:28, but the nova-compute is delcaring the endpoing not found at 06:40:24 | |
| 14:58:28 | cdent | s/that log/the placement api log/ | |
| 14:58:45 | dansmith | johnthetubaguy: gotcha, so confusing | |
| 14:58:52 | EmilienM | let me check when endpoint is created | |
| 14:58:55 | johnthetubaguy | 2017-02-08 06:40:28.684 is when placement starts | |
| 14:58:56 | EmilienM | would it recheck later? | |
| 14:59:10 | mriedem | the compute will keep trying | |
| 14:59:18 | johnthetubaguy | 2017-02-08 06:40:29.306 is first request | |
| 14:59:38 | mriedem | the scheduler will keep trying to, but not per request | |
| 15:00:05 | EmilienM | endpoint is created at 06:38:25 | |
| 15:00:26 | EmilienM | oh wait no, it's for regionOne/nova::compute | |
| 15:00:27 | EmilienM | not placement | |
| 15:00:29 | dansmith | surely the credentials are created by that time right? | |
| 15:00:46 | dansmith | I figure they must be created before they're written to the configfile yes? | |
| 15:00:59 | EmilienM | 06:38:25 centos-7-2-node-osic-cloud1-s3500-7172104-416160 os-collect-config: #033[mNotice: /Stage[main]/Nova::Keystone::Auth_placement/Keystone::Resource::Service_identity[placement]/Keystone_endpoint[regionOne/placement::placement]/ensure: created | |
| 15:01:53 | EmilienM | and it's highly possible nova-compute starts afterward | |
| 15:02:35 | EmilienM | err, before I mean. I checked and nova-compute started at 06:32:06 | |
| 15:02:49 | EmilienM | 06:32:06 centos-7-2-node-osic-cloud1-s3500-7172104-416160 os-collect-config: #033[mNotice: /Stage[main]/Nova::Compute/Nova::Generic_service[compute]/Service[nova-compute]/ensure: ensure changed 'stopped' to 'running' | |
| 15:03:01 | cdent | EmilienM: right, which explains the change from endpoint not found to "Placement service credentials do not work." | |
| 15:03:20 | EmilienM | right, but IIUC it should retry | |
| 15:03:21 | cdent | in the nova-compute logs | |
| 15:03:25 | cdent | it does | |
| 15:03:31 | cdent | that's why we get the change | |
| 15:03:43 | cdent | can't find endpoint, wait, retry, found endpoint credentials don't work | |