Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-10-31
14:58:51 mriedem dansmith: so lots of functional tests inherit it unknowingly
14:59:07 dansmith yeah
14:59:14 sean-k-mooney yep most proably would work fine without it
14:59:24 sean-k-mooney well provied the messageing worked
15:03:54 dansmith mriedem: so that mysql 16m packet patch of yours
15:04:22 dansmith oh, I see you saw the problem even on that eh?
15:05:17 mriedem not sure, i haven't dug into the grenade jobs on that one - unless i did and commented
15:05:22 mriedem i did see the aborted connections though
15:05:26 mriedem not the grenade failure though i don't think
15:05:47 mriedem but yeah the point is that is supposed to avoid the aborted connections
15:06:04 dansmith the mysql side of the error you mean
15:06:08 mriedem right
15:06:21 dansmith I was going to say, let's just merge that and see,
15:06:28 dansmith but maybe not worth it if you still saw those
15:06:35 mriedem right
15:06:48 mriedem kind of would like zzzeek to validate that kind of thing
15:07:04 dansmith those aborted connections definitely seem like they have to be a bad thing
15:07:08 mriedem the change on top that enables query logging - the gd mysql slow log file is so big you can't open it
15:08:00 dansmith mriedem: we don't capture etc/my.cnf it looks like so we can't validate that you set it properly right?
15:18:50 mriedem yeah that's a todo
15:19:10 dansmith mriedem: did you look for other evidence that it was set right? I dunno if it logs anything useful
15:20:04 dansmith looks like we only get error logs
15:21:04 dansmith I see the sudo log with the sed command at least
15:24:00 dansmith mriedem: ah, that message can come from a client just dropping the connection, which could maybe be happening due to connection pooling or something less problematic
15:24:05 dansmith the mysql-side error message I mean
15:24:39 mriedem ok
15:25:58 mriedem so this mostly hits in master patches, so grenade master == stable/train old and ussuri new, i'll check some stable/stein patches to see if their grenade logs have the same mysql aborted connection messages
15:26:17 dansmith ack
15:27:00 mriedem yeah this is a stein patch that merged on 10/26, seeing the same stuff in here https://zuul.opendev.org/t/openstack/build/7fd7bdb35ade439c81023b0fb0846ee8/log/logs/mysql/error.txt.gz
15:27:46 mriedem i wonder if there is some mysql diagnostics command we can run post-upgrade after calling verify_instance (which hits cell1) but before running smoke tests
15:28:44 dansmith well, I'm kinda thinking that this is just fallout from things we don't control, like the db connection pooling (or even api workers under uwsgi never getting scheduled)
15:28:51 dansmith unrelated to the scheduler thing
15:29:13 dansmith also, hmm
15:29:15 mriedem but something changed in train/ussuri obviously
15:29:33 dansmith mriedem: those errors say the user is "root".. aren't the services using actual users to connect to mysql?
15:31:43 mriedem connection = mysql+pymysql://root:secretmysql@127.0.0.1/nova_api?charset=utf8
15:31:46 mriedem ...
15:31:47 mriedem i guess not
15:31:51 mriedem https://storage.gra1.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_8ec/688419/2/check/grenade-py3/8ec542b/logs/etc/nova/nova.conf.txt.gz
15:31:53 dansmith huh.
15:32:32 mriedem same in stein for a non-grenade job https://zuul.opendev.org/t/openstack/build/6cd13330e99346e4b688f35ec2a7ed36/log/controller/logs/etc/nova/nova_conf.txt.gz
15:34:01 mriedem yeah DATABASE_USER in devstack defaults to MYSQL_USER which defaults to root
15:35:51 dansmith okay always thought it was stack or nova or something
15:35:55 mriedem https://docs.openstack.org/nova/train/configuration/config.html#database.connection_recycle_time defaults to 1 hour, i wonder if we should drop that to like 10 minutes or something - not sure it would help anything
15:37:43 dansmith ah, like max_requests
15:37:53 dansmith the failure happens really early in the run though right?
15:38:06 mriedem post-upgrade?
15:38:36 dansmith yeah
15:38:42 dansmith early after starting services Imean
15:39:05 dansmith so if you set recycle to 1s maybe it would be doing lots of reconnecting and we could see if that matters, but it doesn't seem like a fix
15:39:08 dansmith connection+debug=100 maybe?
15:39:11 mriedem yeah i think so. last i checked the funny thing is we run verify_instance post-upgrade which is ok and then grenade tries to create a server or run tempest smoke and things fall over
15:39:59 dansmith yeah, but verify_instance wouldn't be the scheduler,
15:40:05 dansmith so if the scheduler is the only one affected somehow...
15:41:18 dansmith hmm
15:41:23 dansmith is scheduler getting restarted at all?
15:41:27 mriedem it's not only the scheduler, just mostly. some jobs hit it in the api too
15:41:37 mriedem yes scheduler gets restarted in the grenade run
15:41:53 dansmith I don't see it in the log
15:42:08 dansmith oh, I'm looking at a normal job
15:42:11 openstack Launchpad bug 1844929 in OpenStack Compute (nova) "grenade jobs failing due to "Timed out waiting for response from cell" in scheduler" [High,Confirmed]
15:42:11 mriedem i have some notes here https://bugs.launchpad.net/nova/+bug/1844929/comments/3
15:42:33 dansmith I know, I read those previously, but I'm trying to avoid re-reading them to not get stuck down a given line of thinking
15:42:43 mriedem we restart the scheduler and it queries compute nodes and services from the cell1 db at that time ok
15:42:50 mriedem ack
15:43:18 dansmith I know we should,
15:43:38 dansmith I was just wondering if maybe we don't restart it actually and the first attempt fails
15:44:07 dansmith so,
15:44:08 dansmith https://storage.gra1.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_8ec/688419/2/check/grenade-py3/8ec542b/logs/screen-n-sch.txt.gz
15:44:16 dansmith I see it started at 14:07:00 only
15:44:48 dansmith are we not keeping the log or something maybe?
15:46:00 mriedem it looks like that job failed smoke tests on the old side,
15:46:03 mriedem so never got to upgrade
15:46:11 mriedem https://storage.gra1.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_8ec/688419/2/check/grenade-py3/8ec542b/logs/grenade.sh.summary.txt.gz
15:46:20 dansmith okay but the same error
15:46:36 mriedem oh that's interesting
15:51:33 dansmith the first instance of that happens well after the last "aborted connection" message in the mysql error log
15:51:54 dansmith which makes me think all those errors in the mysql log are from things we're doing during devstack setup
15:52:02 dansmith like one-shot client calls or something
15:53:09 dansmith and 18 minutes after the last "ready for connections" message from mysql
15:57:15 dansmith doesn't really look like any sort of unreasonable load or kernel events around that time
16:11:35 dansmith mriedem: https://review.opendev.org/#/c/692402/
16:12:14 dansmith mriedem: have any tricks to get a lot of grenade runs on that?
16:12:39 dansmith I know in the past we'd create like ten noop patches that depends-on something like that to get 10x the runs
16:12:47 dansmith seems irresponsible in today's climate :)
16:16:38 mriedem you could create a grenade patch that depends-on it
17:05:54 openstackgerrit Lee Yarwood proposed openstack/nova master: WIP service: Do not perform version checks for deleted services https://review.opendev.org/692412
17:06:05 lyarwood melwitt: ^ when you're back, I'm likely missing something obvious here.
17:11:48 mriedem lyarwood: didn't mel already fix that bug in the Instance object when lazy-loading services?
17:12:25 mriedem https://review.opendev.org/#/c/582408/
17:14:19 lyarwood mriedem: that was the original bug when running through this upgrade scenario yeah but instead of ServiceNotFound we now see ServiceTooOld raised with that fix applied
17:25:06 mdbooth sean-k-mooney: https://review.opendev.org/#/c/687957/
17:29:08 sean-k-mooney mdbooth: thanks for the review. ill go though it tommorow im just about to go have dinner
17:29:28 mdbooth sean-k-mooney: ack
17:30:20 sean-k-mooney by the way i belive the way im comparing the numa toplogy constirant should compare things like pages size too
17:30:58 sean-k-mooney we dont actully want to try and fit the request to a host and compare that we just want to extrat the contaritns and assert they dont change
17:31:59 sean-k-mooney i can add some more test cases however to test different type of constraitn changes
17:32:24 sean-k-mooney to ensure that change hugpeage also will be detected ectra
17:32:52 sean-k-mooney i assume that is what you ment by poking at different levels
17:33:21 mdbooth sean-k-mooney: Yeah, I wasn't 100% on that, although I *did* go look up 1) the implementation of obj_to_primitive(), 2) the implementation of dict.__eq__ in python ;)

Earlier   Later