| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-03-07 | |||
| 19:36:34 | dansmith | mnaser: because after the log dump: http://logs.openstack.org/08/641308/2/check/openstack-ansible-deploy-aio_lxc-centos-7/2485c9a/logs/openstack/aio1-nova/nova-compute.log.txt.gz#_2019-03-06_12_12_55_326 | |
| 19:36:41 | dansmith | er, conf dump | |
| 19:36:50 | dansmith | that seems extremely wrong | |
| 19:37:09 | dansmith | and may explain why people think that "reset events" change is necessary, because we're incorrectly really exiting? | |
| 19:37:46 | mnaser | it looks like a new startup based on the logs | |
| 19:37:56 | dansmith | yeah that's uncool | |
| 19:38:11 | mnaser | esp with things like updating inventory, libvirt baseline cpu checks, etc | |
| 19:38:19 | dansmith | so I'm guessing some oslo.service regression, or some underlying change that nova didn't adapt to | |
| 19:40:18 | mnaser | following the code it looks like service.Service implements .reset() and hits self.manager.reset() | |
| 19:40:36 | dansmith | our service does yeah | |
| 19:40:54 | dansmith | we also need this to work for things like api to be able to re-calculate service versions, rpc pins,e tc | |
| 19:41:02 | dansmith | and clearing the cells cache | |
| 19:41:14 | mnaser | yeah, so it looks like nova is doing what its supposed to | |
| 19:41:24 | dansmith | so if this is broken it's a real problem, in addition to apparently causing compute to just drop everything on the floor and bail | |
| 19:41:44 | mnaser | the confirmation is the fact all conf params are being logged | |
| 19:41:48 | mnaser | which shouldnt happen | |
| 19:41:58 | mnaser | i think ? because we are handling reset() in our own way | |
| 19:42:04 | dansmith | well, | |
| 19:42:17 | dansmith | sighup is how you're supposed to reload dynamic conf variables | |
| 19:42:26 | dansmith | so I dunno if it should only dump the reloaded ones or the whole new set | |
| 19:42:39 | dansmith | initially that wouldn't have surprised me, but now that I see it saying "starting..." again, I do wonder | |
| 19:42:48 | dansmith | but yeah, this also kills the ability to hot-reload conf options like debug=True | |
| 19:43:18 | mnaser | we probably don't exactly have gating that reloads services and checks if they're still functional after, but that's awfully hard to test in the first place | |
| 19:43:33 | dansmith | yup, definitely hard to test with a parallel tempest | |
| 19:43:38 | dansmith | we could do a post hook though pretty easy | |
| 19:44:11 | dansmith | like set debug=False, sighup, and make sure the log didn't get another debug-esque message that would have come | |
| 19:44:23 | dansmith | I bet mriedem gets all tingly just thinking about such at hing | |
| 19:44:38 | dansmith | I think he <3's post hook test validation | |
| 19:45:30 | mriedem | shut up gawd | |
| 19:46:03 | mnaser | the only thing i can imagine is | |
| 19:46:14 | mnaser | https://github.com/openstack/oslo.service/blob/471bfe770808a0348fcce1e83753dcc414b361c1/oslo_service/service.py#L395-L397 | |
| 19:46:26 | mnaser | that somehow evaluating to false and calling self.restart() | |
| 19:46:44 | dansmith | because of systemd not running us in daemon mode or something? | |
| 19:47:02 | dansmith | https://github.com/openstack/oslo.service/blob/471bfe770808a0348fcce1e83753dcc414b361c1/oslo_service/service.py#L58 | |
| 19:47:30 | dansmith | yep, | |
| 19:48:06 | dansmith | if stdout is closed or not a tty, then we're in daemon mode, else no | |
| 19:48:20 | mnaser | but stdout is probably open because of how systemd works | |
| 19:48:21 | dansmith | I'm guessing maybe systemd runs us with a pty for stdout in foreground mode and that's fooling it? | |
| 19:48:28 | mnaser | let me | |
| 19:48:33 | mnaser | lsof a running instance now | |
| 19:48:45 | dansmith | I'm pretty sure it uses a pty, | |
| 19:48:59 | dansmith | because if you run a python program as a systemd unit, you have to turn off output buffering to see live output | |
| 19:50:13 | dansmith | could probably defeat that by running compute |tee and see if that changes the behavior | |
| 19:51:37 | mnaser | looks like there is a systemd option called 'DefaultStandardOutput' | |
| 19:51:44 | mnaser | which defaults to 'journal' | |
| 19:51:56 | dansmith | well, sure. | |
| 19:52:08 | dansmith | but you want that unless you're using native systemd logging | |
| 19:52:29 | mnaser | yeah, but that also means that stdout is not closed => we're not in daemon mode, right? | |
| 19:52:49 | dansmith | it's not just closed, it's closed or not a tty | |
| 19:52:57 | dansmith | per that is_daemon() method right? | |
| 19:53:25 | dansmith | # the process is running in the background as a daemon. | |
| 19:53:25 | dansmith | # not match, or ioctl() fails on the stdout file handle, we assume | |
| 19:53:25 | dansmith | # process group of the controlling terminal. If those values do | |
| 19:53:25 | dansmith | # The process group for a foreground process will match the | |
| 19:54:02 | dansmith | if systemd is running us with a pty for stdio, that will assume we're in interactive mode and say we're not a daemon, which means sighup->restarts (for some reason which I'm not even sure is legit) | |
| 19:54:28 | mnaser | ok let me just drop that python code in a simple systemd unit and see what happens | |
| 19:58:11 | dansmith | also would be useful to just take a system running like this and put a debug print() in that thing to see if we're returning !daemon for any reason | |
| 19:59:51 | mnaser | bleh, returning true | |
| 20:00:51 | mnaser | http://paste.openstack.org/show/747426/ | |
| 20:01:19 | dansmith | not sure that's a really legit test, | |
| 20:01:31 | dansmith | because any other service startup stuff could impact that | |
| 20:01:44 | dansmith | like chdir(), close existing fds, logging setup, etc | |
| 20:01:56 | dansmith | I think it'd be more useful to just instrument a misbehaving openstack service | |
| 20:01:59 | mnaser | ok so let me do it on a machine i have here then | |
| 20:02:03 | mnaser | on an actual nova-compute | |
| 20:04:28 | mnaser | _is_sighup_and_daemon: True | |
| 20:04:50 | mnaser | which means | |
| 20:04:56 | mnaser | if not True: .. so it doesn't break and does a restart | |
| 20:05:05 | mnaser | wait what, shouldn't that be if _is_sighup_and_daemon(signo): break ? | |
| 20:05:26 | mnaser | given that we don't want to restart if we get a sighup and running in daemon mode? | |
| 20:06:22 | dansmith | hrm, yeah | |
| 20:06:25 | mnaser | https://github.com/openstack/oslo.service/commit/94e76035c627e003f601c6501c0f414a13160f1f#diff-49ecd82bf041c1fd494a0bc4a96782deR195 | |
| 20:06:28 | dansmith | tbh, I don't know why this logic is here regardless | |
| 20:06:55 | dansmith | ...newton | |
| 20:07:00 | mnaser | yeah it's been a hot minute | |
| 20:07:05 | mnaser | lol | |
| 20:07:05 | mnaser | i really hope it hasn't been broken that whole time | |
| 20:07:15 | dansmith | that was around the time of the great systemdification of devstack, and because sdague | |
| 20:07:17 | dansmith | so really fishy | |
| 20:07:26 | dansmith | but sounds like something is broken to me | |
| 20:08:05 | mnaser | ok ill try to ping doug | |
| 20:09:19 | dansmith | I don't really agree with the assertion made in the commit message of that | |
| 20:09:33 | dansmith | because it assumes that we're only a long-lived service if we've daemonized ourselves | |
| 20:09:59 | dansmith | mnaser: also note that systemd can handle self-daemonizing services, so it depends on how your particular unit is running nova-compute too | |
| 20:11:08 | mnaser | dansmith: yeah, afaik we use type=simple so it's the "run in foreground mode forever" model | |
| 20:11:15 | dansmith | ack | |
| 20:11:46 | openstackgerrit | Artom Lifshitz proposed openstack/nova master: Dont' wait for VIF plugging during revert resize https://review.openstack.org/639396 | |
| 20:12:09 | dansmith | mnaser: assume you don't have a bug open for this yet right? | |
| 20:19:22 | mriedem | someone should uh, put some time into figuring out what to do about this old ass statement https://github.com/openstack/nova/blob/master/nova/compute/resource_tracker.py#L1380 | |
| 20:19:47 | mnaser | bug | |
| 20:19:53 | mnaser | gah ctrl+f doesnt exist i guess | |
| 20:25:56 | openstackgerrit | Chris Dent proposed openstack/nova master: Integration tests using gabbi-tempest https://review.openstack.org/613386 | |
| 20:26:57 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Remove unused context parameter from RT._get_instance_type https://review.openstack.org/641792 | |
| 20:41:05 | openstackgerrit | Merged openstack/nova master: Separate methods to free claimed and allocated devs https://review.openstack.org/616120 | |
| 21:10:47 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Update usage in RT.drop_move_claim during confirm resize https://review.openstack.org/641806 | |
| 21:13:34 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Update usage in RT.drop_move_claim during confirm resize https://review.openstack.org/641806 | |
| 21:16:09 | mikal | Given the sudden burst of interest in the privsep patches, is it worth asking for a FFE? | |
| 21:17:45 | mriedem | nope | |
| 21:17:54 | mikal | Fair enough. | |
| 21:18:04 | mikal | I wont rush to deal with new review comments then. | |