| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-06-18 | |||
| 20:31:55 | anupn | mriedem: Okay so with --verbose, I see it finds two cells - cell0 and cell1 | |
| 20:32:00 | dansmith | zcorneli: no need to assert the presence of all the things for the latest version, IMHO | |
| 20:32:07 | dansmith | zcorneli: just one to make sure you're not looking at the wrong level of the structure | |
| 20:32:07 | anupn | it is skips cell0 as no hosts in that | |
| 20:32:42 | anupn | " | |
| 20:32:42 | anupn | Found 0 unmapped computes in cell: 182677b0-4e7d-416b-a47b-57c2f33e090e | |
| 20:32:42 | anupn | and from cell1 I see - "Getting computes from cell 'cell1': 182677b0-4e7d-416b-a47b-57c2f33e090e | |
| 20:33:01 | zcorneli | Seems like the positive assertion for every field is "clear" - It should be covered elsewhere in the tests as well, but ensures "It was there before making compatible, and not there after" | |
| 20:33:10 | mriedem | anupn: what does this give you? nova-manage cell_v2 list_hosts 182677b0-4e7d-416b-a47b-57c2f33e090e | |
| 20:33:19 | mriedem | does the compute host that's hosting that baremetal node show up in the list? | |
| 20:33:41 | zcorneli | dansmith: The single definitely helps fix the previous issue we had through with the false positives | |
| 20:33:50 | dansmith | right | |
| 20:34:14 | dansmith | zcorneli: you're welcome to positive-assert your property if you want, but I don't think it's that necessary | |
| 20:35:17 | anupn | mriedem: yes | |
| 20:35:26 | mriedem | anupn: ok so then the host is mapped to cell1 | |
| 20:35:32 | anupn | I see the hostname of my node | |
| 20:35:39 | mriedem | anupn: try scheduling now | |
| 20:35:54 | zcorneli | dansmith: I'm OK with the statement that the positive side is covered elsewhere. | |
| 20:36:38 | anupn | mriedem: Okay, wait but "openstack hypervisor list" shouldn't it show my ironic type hypervisor? | |
| 20:36:38 | openstackgerrit | Artom Lifshitz proposed openstack/nova master: DNM: Use claim context during live migration https://review.openstack.org/576222 | |
| 20:36:57 | mriedem | anupn: yes | |
| 20:36:59 | anupn | mriedem: oh yeah, it shows now | |
| 20:37:06 | mriedem | whew | |
| 20:37:16 | anupn | mriedem: so I think scheduling should work now | |
| 20:37:20 | mriedem | i hope so | |
| 20:37:28 | anupn | mriedem: what commands, made this magic? | |
| 20:37:34 | mriedem | discover_hosts --by-service | |
| 20:37:35 | mriedem | presumably | |
| 20:37:52 | anupn | mriedem: Ah, that's interesting, worth making a note | |
| 20:43:25 | anupn | mriedem: Instance got scheduled like charm :) | |
| 20:43:40 | anupn | thanks | |
| 20:44:26 | mriedem | anupn: cool, yw | |
| 20:51:09 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Fix regression when listing build_requests with marker and ip filter https://review.openstack.org/576161 | |
| 20:56:49 | openstackgerrit | Eric Fried proposed openstack/nova master: Tighten up ReportClient use of generation https://review.openstack.org/556669 | |
| 20:57:54 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Clarify placement DB schema migration https://review.openstack.org/576265 | |
| 20:59:53 | SpamapS | So.. question about placement service logs.. | |
| 21:00:00 | SpamapS | They're basically destroying our ELK stack | |
| 21:00:05 | SpamapS | is there any value in logging all of that at INFO? | |
| 21:10:59 | openstackgerrit | Eric Fried proposed openstack/nova-specs master: Spec: Handling Reshaped Provider Trees https://review.openstack.org/572583 | |
| 21:13:16 | openstackgerrit | Eric Fried proposed openstack/nova-specs master: Spec: Handling Reshaped Provider Trees https://review.openstack.org/572583 | |
| 21:13:53 | efried | SpamapS: You can bust the log level down if you like. | |
| 21:14:19 | efried | SpamapS: What kind of logging are you seeing? I haven't looked at one lately. | |
| 21:16:20 | openstackgerrit | Chris Dent proposed openstack/nova master: Isolate placement database config https://review.openstack.org/541435 | |
| 21:16:34 | openstackgerrit | Chris Dent proposed openstack/nova master: Ensure that os-traits sync is attempted only at start of process https://review.openstack.org/553857 | |
| 21:19:26 | openstackgerrit | Dan Smith proposed openstack/nova stable/queens: Add amd-ssbd and amd-no-ssb CPU flags https://review.openstack.org/576270 | |
| 21:25:11 | jroll | efried: random tempest-full run on INFO: http://logs.openstack.org/66/362766/109/gate/tempest-full/52a4e60/controller/logs/screen-placement-api.txt.gz?level=INFO | |
| 21:25:17 | jroll | that is certainly a lot of logs | |
| 21:25:32 | jroll | looks like it's logging each request at INFO | |
| 21:25:44 | efried | jroll: Is that not what it should be doing? | |
| 21:25:56 | efried | It's not logging payloads. | |
| 21:26:02 | efried | That would be DEBUG-worthy. | |
| 21:26:04 | jroll | I don't know, I don't make those decisions :P | |
| 21:26:18 | zcorneli | dansmith: For that test fixup, looks like there's a number of similar issues in the objects/ dir, worth fixing them all? | |
| 21:26:33 | jroll | efried: in my experience, apache/nginx/whatever does the request logging, and the service only logs whatever else is needed | |
| 21:26:55 | jroll | but clearly someone decided at some point this should happen in placement at info ¯\_(ツ)_/¯ | |
| 21:27:17 | efried | cdent, jaypipes - what are your thoughts on making placement logging less noisy? | |
| 21:27:41 | efried | jroll: I mean, you can always bust the log level down, right? | |
| 21:28:06 | jroll | efried: I assume there are some important things logged at INFO | |
| 21:28:39 | efried | jroll: You mean in general, or here? | |
| 21:28:48 | jroll | both? | |
| 21:28:50 | efried | cause here all I see is just the calls. | |
| 21:29:06 | jroll | well that's the point, signal-to-noise ratio is low | |
| 21:30:12 | jroll | to be clear, I don't (currently) have a problem, just got curious | |
| 21:30:38 | efried | and what I'm saying is, if these lines about which operations are called and how long they took and how many bytes they generated are all considered "noise", you can switch to WARNING and you'll get not those, but you (seemingly) won't lose out on anything else. | |
| 21:30:51 | efried | Ima go look see if there's anything else logged at INFO... | |
| 21:30:59 | jroll | I just checked, heh | |
| 21:31:09 | jroll | curl http://logs.openstack.org/66/362766/109/gate/tempest-full/52a4e60/controller/logs/screen-placement-api.txt.gz\?level\=INFO | grep -v nova.api.openstack.placement.requestlog | grep -v 'switches on core' | grep INFO | |
| 21:31:19 | jroll | gives a single line | |
| 21:31:44 | efried | Yeah, traits db sync and online migration are the only other two things in the code. | |
| 21:31:49 | jroll | so you're right, there isn't really anything other than request logging at INFO | |
| 21:32:07 | efried | (online _data_ migration, that is - nothing to do with migrating instances) | |
| 21:32:13 | jroll | most openstack services log very useful things at INFO, so operators tend to run at INFO | |
| 21:32:21 | SpamapS | "Info: Usually indicates successful service start/stop, versions and such non-error related data. This should include largely positive units of work that are accomplished (such as starting a compute, creating a user, deleting a volume, etc.)" | |
| 21:33:07 | efried | useful is in the eye of the beholder, I suppose. | |
| 21:33:08 | SpamapS | https://specs.openstack.org/openstack/openstack-specs/specs/log-guidelines.html | |
| 21:33:18 | SpamapS | IMO those should be TRACE | |
| 21:33:19 | efried | SpamapS: I don't really see this as violating that precept, personally. | |
| 21:33:36 | SpamapS | They aren't really useful for realtime analysis. | |
| 21:33:45 | efried | No, trace would include all the payloads, generated SQL statements and result sets, etc. | |
| 21:33:47 | SpamapS | They're good for like, tracing through to find out when an aggregate changed to what or was requested as what. | |
| 21:34:08 | SpamapS | but every single compute node is constantly hitting placement | |
| 21:34:39 | efried | Put in the context of the other logs, the info level is useful for letting you figure out which calls happened when and what their result was. | |
| 21:35:19 | efried | Keeping in mind that placement doesn't necessarily see a 4xx as a "failure" or whatever, so something that's an ERROR in n-cpu or n-cond or whatever might just be a vanilla request/response to placement. | |
| 21:35:28 | efried | So we can't condition on status code. | |
| 21:35:55 | efried | Turn it around: if we were to take these lines out of INFO level, the log would be basically empty. | |
| 21:36:17 | SpamapS | Ya, at this point we're just going to dump them from our ELK cluster. | |
| 21:36:28 | SpamapS | They represent ~70% of all logs flowing in. | |
| 21:36:49 | efried | SpamapS: I'm going to say again, if you don't like these INFO messages, change the log level (for placement only) to WARNING. | |
| 21:37:10 | SpamapS | Ya, just wondering why people would think these would be useful enough for INFO. | |
| 21:37:12 | efried | SpamapS: Because I reckon you do want to know if something goes wrong. So you don't just want to blow away the logs. | |
| 21:37:45 | SpamapS | Yeah thats what I meant by dump them.. we'll not send the INFO+placement through to elastic. | |
| 21:38:11 | efried | SpamapS: For ffdc, being able to correlate an ERROR in the nova logs to the corresponding placement calls - that's useful. And INFO-worthy IMO. | |
| 21:38:47 | efried | again because placement has no way to distinguish what's ERROR-worthy from the client's perspective. | |
| 21:39:22 | efried | Also finding it a little hard to believe that the placement log is noisier than the combined compute logs. Keep in mind that there's only one placement service. | |
| 21:39:54 | SpamapS | the computes don't spray as much on INFO | |
| 21:40:06 | SpamapS | unless they're super busy with churn | |
| 21:40:43 | SpamapS | meanwhile they're constantly hammering on placement | |
| 21:40:48 | efried | yup | |
| 21:52:01 | jaypipes | SpamapS, jroll: do you have specific advice on what to down-level from INFO? | |
| 22:07:02 | Sundar | efried: Please ping me when you can | |