| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-07-27 | |||
| 19:28:21 | melwitt | mriedem: right, thanks | |
| 19:28:24 | mriedem | i only see 3 in there that wouldn't be deferred | |
| 19:28:33 | mriedem | mox-removal, versioned notifications and stephen's numa vswitch bp | |
| 19:28:54 | melwitt | thanks | |
| 19:29:09 | sean-k-mooney | dansmith: am could we use a decoreator/context manager to also chagne the config for spcific call? | |
| 19:29:49 | dansmith | sean-k-mooney: not sure I parsed that, but I think we'd not want to override log levels in a context manager | |
| 19:30:43 | sean-k-mooney | basically im thinking about your previous suggstion of a decorator for this is sensitive never logit cases | |
| 19:30:59 | dansmith | sean-k-mooney: yep, something intentional for this might be good | |
| 19:31:30 | melwitt | setting the default log level for oslo.privsep is a good mitigation we can do immediately. then we can look at the idea of adding something to oslo.privsep to control this in a better, non-overrideable way (though I guess one could argue if the user really wants to override, they should be able to) | |
| 19:31:38 | sean-k-mooney | the default log level change is also good but that read tty call proablly should never be logged | |
| 19:32:20 | sean-k-mooney | melwitt: if the user really want to log it that much they could add a print() | |
| 19:32:39 | sean-k-mooney | or remvoe the decorator | |
| 19:32:57 | sean-k-mooney | its likely that you would only want to do this if your debugging | |
| 19:33:26 | melwitt | yeah, I just meant to point out it's a consideration. not arguing either way | |
| 19:36:13 | sean-k-mooney | ya thats true | |
| 19:36:46 | mriedem | the default_log_levels things is backportable, which i'm assuming this needs to be | |
| 19:36:49 | mriedem | we've had privsep in for awhile | |
| 19:37:15 | dansmith | I've been trying to git-review this mofo for a few minutes now | |
| 19:38:04 | sean-k-mooney | well the default_log_levels can be set in deployment tools so it can be done downstream also even if it was not upstream | |
| 19:38:45 | openstackgerrit | Dan Smith proposed openstack/nova master: Force oslo.privsep.daemon logging to INFO level https://review.openstack.org/586643 | |
| 19:38:50 | dansmith | thar ^ | |
| 19:39:40 | dansmith | we can check the logs after a run of that and make sure theres no privsep debug noise in there | |
| 19:51:22 | sean-k-mooney | dansmith: the only down side to this change is i used to use some of those log messages to debug os-vif plugging stuff but in heighsight i should have proably questioned why they were there | |
| 19:51:28 | sean-k-mooney | dansmith: that said http://logs.openstack.org/63/586363/3/check/legacy-tempest-dsvm-full-devstack-plugin-ceph/569c574/logs/screen-n-cpu.txt.gz#_Jul_27_17_31_34_229614 | |
| 19:51:44 | dansmith | sean-k-mooney: this is just the default, you can still override it in config to turn it on | |
| 19:52:01 | sean-k-mooney | this is being loged form the privsep deamon but reported as oslo_concurrency | |
| 19:52:28 | sean-k-mooney | dansmith: oh i know, what will we do in the gate? | |
| 19:53:12 | dansmith | well, we can override this for the gate, it just needs to not be on by default | |
| 19:54:06 | dansmith | sean-k-mooney: are you sure? that doesn't look like the privsep format | |
| 19:54:18 | dansmith | and processutils would log something like that | |
| 19:54:39 | dansmith | maybe it's inside the daemon, but running processutils, which is emitting the actual log? | |
| 19:54:42 | sean-k-mooney | dansmith: that code is executed via privsep but that message is not from that log | |
| 19:54:52 | sean-k-mooney | dansmith: yes | |
| 19:55:17 | dansmith | okay I'm confused about what you're saying | |
| 19:55:33 | sean-k-mooney | sorry one sec | |
| 19:56:44 | sean-k-mooney | its basically this https://github.com/openstack/os-vif/blob/master/vif_plug_ovs/linux_net.py#L155 | |
| 19:56:55 | sean-k-mooney | which invokes processuitls here https://github.com/openstack/os-vif/blob/master/vif_plug_ovs/linux_net.py#L58 | |
| 19:58:18 | sean-k-mooney | the actull privsep request message is printed here http://logs.openstack.org/63/586363/3/check/legacy-tempest-dsvm-full-devstack-plugin-ceph/569c574/logs/screen-n-cpu.txt.gz#_Jul_27_17_31_34_229139 | |
| 19:59:21 | sean-k-mooney | but any loging privledge fucntions do is also relyed to the parent over the socket. | |
| 20:02:30 | sean-k-mooney | anyway lets see if that config option just effect the default log level of oslo.privspes own internal logging or also the suff call via a privsep context | |
| 20:03:16 | dansmith | okay, I'm still not sure what your concern is | |
| 20:03:23 | dansmith | but it's probably my friday brain | |
| 20:03:39 | openstackgerrit | Artom Lifshitz proposed openstack/nova master: DNM: Extra logs for volume detach device tags cleanup https://review.openstack.org/584032 | |
| 20:04:45 | sean-k-mooney | well im hoping that oslo.preivsep.deamon=INFO just disables the debug loggin for privsep debug logs but not debug logs from things called via privsep | |
| 20:05:19 | dansmith | why? | |
| 20:05:40 | dansmith | it should affect anything that logs with oslo.privsep.daemon, not anything else | |
| 20:06:05 | dansmith | if those concurrency logs are logged with a logger name of oslo.concurrency.processutils, then they should be unaffected | |
| 20:06:07 | dansmith | is that what you mean? | |
| 20:06:26 | sean-k-mooney | yes. | |
| 20:06:39 | dansmith | okay I think we'll be okay on that, assuming it works the way I think it does | |
| 20:06:45 | dansmith | I expect there is some code in privsep that does: | |
| 20:07:12 | dansmith | for message_logged_in_the_daemon: logger.getLogger(message.log_name).log.$level(message.msg) | |
| 20:07:42 | dansmith | so my change should only affect actual messages logged on the daemon log name | |
| 20:07:58 | dansmith | not anything logged in the context of the daemon at all | |
| 20:08:29 | dansmith | hmm, that code was kindof nonsense, let me try again: | |
| 20:08:33 | sean-k-mooney | its this code that i was unsure about https://github.com/openstack/oslo.privsep/blob/master/oslo_privsep/daemon.py#L249-L254 | |
| 20:08:38 | itlinux | hello Nova guys, when spinning up a VM, and the hypervisor is asking to pull the image from glance does that go over the storage network? thanks | |
| 20:09:08 | dansmith | sean-k-mooney: that's the daemon-side code that intercepts the logs to redirect | |
| 20:09:19 | sean-k-mooney | yes | |
| 20:09:22 | dansmith | it's the non-daemon code that does the actual logging and would do what I surmised above | |
| 20:09:30 | sean-k-mooney | well part of it | |
| 20:09:59 | sean-k-mooney | anyway we will see soon. | |
| 20:15:40 | dansmith | yup | |
| 20:19:40 | mnaser | there technically should never be rows with cell_id=NULL in instance_mappings.. right? | |
| 20:20:59 | dansmith | mnaser: mappings have no cell until they're scheduled | |
| 20:21:22 | mnaser | :p | |
| 20:21:22 | mnaser | dansmith: right, but yknow, not an instance from march lets say | |
| 20:21:23 | dansmith | they should always end up scheduled, to cell0 at least, but they can be there transiently and/or if something fails | |
| 20:22:41 | mnaser | alright so i think i'll have to write something to look in our cell vs cell0 and update mappings to make the db consistent | |
| 20:46:00 | mriedem | mnaser: same issue from last week right? | |
| 20:46:09 | mriedem | could have been rpc outage so a failed db update | |
| 20:46:13 | mriedem | er db? | |
| 20:46:24 | mriedem | failed write i mean | |
| 20:46:32 | mnaser | mriedem: no it looks like over the lifetime of our cloud any rpc or db related things might have accumulated a lot of things in nova_api with cell_id = NONE | |
| 20:46:36 | mnaser | like, 20000 worth. | |
| 20:46:51 | mriedem | i had also identified one spot in conductor where the build request will be gone and we don't set the instance mapping to cell0 | |
| 20:47:09 | mnaser | however for 99.9999% of those, they were actually assigned a cell and not buried in cell0 | |
| 20:47:52 | mnaser | dansmith, mriedem: http://paste.openstack.org/show/726767/ might be a useful little tool if someone ends up in the same situation | |
| 20:48:17 | mnaser | connect to api db, get all cells, go over them all and check where it can find the instance, and then print out an update statement for manual fix | |
| 20:48:29 | mriedem | we could nova-manage cell_v2 that baby | |
| 20:49:20 | mnaser | i can push up an initial patch but i dunno how much i can iterate/test/etc because i've been a bit overwhelmed | |
| 20:49:36 | mnaser | and it would have to be updated to use nova objects too i guess | |
| 20:49:40 | mriedem | np, or just report a bug and put this paste in it as a template | |
| 20:49:47 | mriedem | latter is fine ^ | |
| 20:49:52 | mnaser | good idea | |
| 20:50:15 | mriedem | is this finding instances in non-cell0 cells? | |
| 20:50:23 | mriedem | that aren't in error state? | |
| 20:50:58 | mnaser | mriedem: im not sure about the exact logic, but i grab a list of all cells, connect to them, and loop until i find an entry inside 'instances' table with the same id | |
| 20:51:02 | mnaser | if that is logically wrong, i can fix it | |
| 20:51:44 | mriedem | it makes sense | |
| 20:51:55 | mriedem | if the instance mapping doesn't tell what cell it's in, we have to iterate the cells looking for it | |
| 20:52:08 | mnaser | and there is no change it ever being in two cells | |
| 20:52:14 | mnaser | s/change/chance/ | |
| 20:52:18 | mriedem | is that a question? | |
| 20:52:22 | mnaser | yes | |
| 20:52:26 | mriedem | shouldn't be no | |
| 20:52:33 | mnaser | okay sounds good, because i break off once i find it and stop looping | |
| 20:52:35 | mriedem | but this shouldn't be happening in the first place | |
| 20:52:51 | mnaser | yeah :\ but i dunno how much to blame nova when it might have been an infra problem | |
| 20:53:14 | mriedem | i mean in a normal case we create the instance in the cell here https://github.com/openstack/nova/blob/6be7f7248fb1c2bbb890a0a48a424e205e173c9c/nova/conductor/manager.py#L1257 | |