Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-10-31
14:51:30 mdbooth mriedem: That was a significant change when I rewrote my test. I see the benefit, though.
14:51:31 sean-k-mooney well i coudl write a generic numa functional base class and use that
14:51:49 sean-k-mooney and then later refactor the libvir one to inherit form it
14:52:31 mdbooth sean-k-mooney: If you went down the route of doing something like mriedem's new base class, but adding libvirtiness, you'd be losing CastAsCall.
14:52:55 sean-k-mooney we dont want the castAsCall stuff right?
14:52:56 mdbooth Which I agree with in principal, especially if we're writing a new base class, as it's quite different.
14:53:10 mdbooth sean-k-mooney: Right, but your base class here will be using it.
14:53:20 mdbooth So I'm wondering what the strength of feeling is there.
14:53:22 sean-k-mooney yes but may tests does not care
14:54:11 mdbooth sean-k-mooney: Ah, crap. I forgot to get coffee before your meeting ;)
14:54:29 sean-k-mooney i need the messaging to work so the service can comunicate but i dont depend on the castascall behavior
14:54:38 sean-k-mooney yep im about to do the same
14:55:33 mriedem efried: logstash isn't showing me hits for that
14:55:36 mriedem in 15 minutes anyway
14:55:56 mriedem efried: it's also only a couple of changes in the last 2 days
14:56:12 mriedem mdbooth: i don't know what sean-k-mooney patch you're referring to
14:56:52 mriedem mdbooth: i feel pretty strongly about not building new tests on anything that uses CastAsCall,
14:57:05 mriedem since it's bogus for testing realistic API behavior which is the point of functional tests
14:57:18 mriedem i'd like to nuke the castascall fixture unless we have a good reason to use it
14:58:10 dansmith mriedem: I agree it creates unrealistic tests, but don't we use it in a crapton of places currently?
14:58:19 sean-k-mooney mriedem: its the numa rebuild patch. which we discussed before as actully not beeing libvirt specific
14:58:29 sean-k-mooney mriedem: and it does not need castascall
14:58:34 mriedem dansmith: it's used in one of the parent classes for the API samples tests
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 mriedem i have some notes here https://bugs.launchpad.net/nova/+bug/1844929/comments/3
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: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

Earlier   Later