| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-04-04 | |||
| 20:45:46 | efried | mdbooth_: anything on this morning's weird db race topic? | |
| 20:45:53 | efried | o, it's like midnight for you. | |
| 21:09:54 | efried | http://logs.openstack.org/01/648601/5/check/openstack-tox-py36/0e12826/testr_results.html.gz | |
| 21:09:54 | efried | http://logs.openstack.org/66/649566/1/check/openstack-tox-py37/e989684/testr_results.html.gz | |
| 21:09:54 | efried | http://logs.openstack.org/53/639453/9/check/openstack-tox-py36/2b6b01f/testr_results.html.gz | |
| 21:09:54 | efried | http://logs.openstack.org/13/621313/21/check/openstack-tox-py36/ba2c848/testr_results.html.gz | |
| 21:09:54 | efried | http://logs.openstack.org/92/627892/21/check/openstack-tox-py37/66b8eab/testr_results.html.gz | |
| 21:09:54 | efried | http://logs.openstack.org/57/649757/1/check/openstack-tox-py37/a965c6b/testr_results.html.gz | |
| 21:09:54 | efried | mriedem: I'm dyin here. Can't figure out how to get logstash to return these. Here are representative examples: | |
| 21:11:20 | mriedem | think i already got it https://review.openstack.org/650136 | |
| 21:12:15 | efried | sigh | |
| 21:12:57 | efried | I was trying to include other parts of the "message". How do you do that? Whenever I use AND it comes back with nothing. | |
| 21:13:25 | efried | fixtures._fixtures.timeout.TimeoutException seems relevant. Because I would have thought that InterfaceException could be caused by any number of things. | |
| 21:13:32 | efried | InterfaceError, rather | |
| 21:15:13 | mriedem | console log entries are indexed as single lines | |
| 21:15:23 | mriedem | so you unfortunately can't do an AND on messages from different lines | |
| 21:15:32 | mriedem | the only multi-line indexing we have is tracebacks in screen logs | |
| 21:15:36 | mriedem | e.g. nova-compute | |
| 21:16:09 | mriedem | which is frustrating with tests that fail like this https://bugs.launchpad.net/nova/+bug/1823215 | |
| 21:16:10 | openstack | Launchpad bug 1823215 in OpenStack Compute (nova) "TestInstanceNotificationSampleWithMultipleComputeOldAttachFlow._test_live_migration_force_complete intermittent fails with MismatchError: 6 != 7" [Medium,Confirmed] | |
| 21:16:21 | mriedem | means we have to do a better job of logging at the point of failure | |
| 21:19:37 | mriedem | melwitt: dansmith: i was going to write up something in our contributor testing reference docs about testing with a down cell in devstack, my notes are here http://paste.openstack.org/show/748904/ - do you see anything in there that i could be missing which might be interesting/useful? | |
| 21:19:56 | mriedem | somewhere linked from here https://docs.openstack.org/nova/latest/contributor/#testing | |
| 21:21:07 | cdent | did any of mdbooth's eventlet clean ups merge? | |
| 21:22:07 | mriedem | cdent: https://review.openstack.org/#/q/topic:bug/1808975+(status:open+OR+status:merged) | |
| 21:22:15 | cdent | because it seems like what the pymysql interface errors are showing is that something has disrupted some delicate timing and a bit of unitidiness in the opportunistic tests is not getting the leeway desired | |
| 21:22:44 | cdent | hmmm, that's further back than would make sense for this | |
| 21:22:45 | mriedem | cdent: i definitely suspect eventlet weirdness with http://status.openstack.org/elastic-recheck/#1793364 | |
| 21:22:50 | mriedem | cdent: but yeah that | |
| 21:22:54 | mriedem | timing doesn't line up with the failures | |
| 21:23:06 | mriedem | i do think we hit some thread switch and then the test just times out | |
| 21:23:17 | mriedem | older notes are in https://bugs.launchpad.net/nova/+bug/1793364 | |
| 21:23:18 | openstack | Launchpad bug 1793364 in Manila "mysql db opportunistic unit tests timing out intermittently in the gate (bad thread switch?)" [Undecided,In progress] - Assigned to Goutham Pacha Ravi (gouthamr) | |
| 21:25:07 | efried | mriedem: https://review.openstack.org/#/c/650043/ is failing in grenade again. Ima rebase it so we don't have to wait for the rest to finish, if you can re+W it? | |
| 21:25:22 | mriedem | sure | |
| 21:25:55 | openstackgerrit | Eric Fried proposed openstack/nova stable/stein: Remove CellMappingPayload database_connection and transport_url fields https://review.openstack.org/650043 | |
| 21:26:11 | efried | mriedem: needed trivial edit ^ since no newer master commit to rebase onto | |
| 21:26:31 | melwitt | mriedem: looks comprehensive to me, I can't think of anything missing other than linking to the docs about what down cell means and such when you propose the patch | |
| 21:26:42 | mriedem | melwitt: yup lots of links to be made | |
| 21:26:50 | mriedem | thanks for looking | |
| 21:26:52 | cdent | if it turns out to be sdist we should decode why. in at least some of our tests runs when sdist is true we'll install requirements as discovered by python setup.py sdist and then install requirements _again_ so there's a possibility that pip is changing it's mind about some things when upper constraints is more involved. hard to say, especially at my late hour | |
| 21:27:07 | melwitt | mriedem: yeah, looks good. good stuff to have in the docs | |
| 21:27:25 | mriedem | efried: you could have chosen something besides the cherry-picked line :) | |
| 21:27:50 | mriedem | well i guess not, whatever | |
| 21:28:04 | mriedem | efried: maybe should ask fungi to promote that? | |
| 21:28:04 | efried | mriedem: Yeah, then it would have differed from its cherry-pick-ees. | |
| 21:28:19 | dansmith | mriedem: why the upgrade levels thing? | |
| 21:28:56 | mriedem | dansmith: because of https://bugs.launchpad.net/nova/+bug/1815697 | |
| 21:28:57 | openstack | Launchpad bug 1815697 in OpenStack Compute (nova) "[upgrade_levels]compute=auto grinds the API response times when a cell is down" [Medium,Confirmed] | |
| 21:29:11 | mriedem | "Also note the default database max_attempts and retry_interval are 10 which means for each API object created that hits this, it's going to take 100 seconds to timeout per route handler per API worker. I count 31 route handlers that create an API object, so that's by default 3100 seconds or about ~52 minutes per worker on startup." | |
| 21:29:21 | dansmith | oh because auto doesn't support the timeouts? | |
| 21:29:23 | melwitt | mriedem, efried: reminder we're also waiting on https://review.openstack.org/649630 it's #1 in the gate but if it fails... | |
| 21:29:34 | dansmith | I think I remember that now | |
| 21:29:38 | efried | fungi: TLDR https://review.openstack.org/#/c/650043/ represents a security regression we're holding nova-stein-rc2 for | |
| 21:29:49 | mriedem | dansmith: not really about the timeouts, it's just we hit that query on each API controller startup x number of API workers | |
| 21:29:51 | efried | melwitt: ack, succeeding so far. | |
| 21:30:02 | efried | though it hasn't finished the freakin grenade-lm job yet | |
| 21:30:18 | mriedem | heh we could have rebased https://review.openstack.org/#/c/650043/ on top of https://review.openstack.org/649630 | |
| 21:30:25 | melwitt | yeah. wanted to point that out in case of gate promotions, we have two that are in flight | |
| 21:32:01 | mriedem | dansmith: https://review.openstack.org/#/c/649197/ was an attempt at something semi-related | |
| 21:33:02 | dansmith | mriedem: oh, is this because we actually start them in threads early enough (because wsgi) that we haven't populated the cache yet? | |
| 21:33:34 | mriedem | well, in my devstack recreate, cell1 is down and cell1 is the only thing that has compute services, | |
| 21:33:43 | mriedem | so we get 0 back for the min compute service version which does not get cached | |
| 21:34:05 | mriedem | https://review.openstack.org/#/c/649197/1/nova/compute/rpcapi.py@424 | |
| 21:34:17 | dansmith | oh okay I meant the perf thing, but that's probably legit too | |
| 21:34:50 | mriedem | also related https://bugs.launchpad.net/nova/+bug/1815692 | |
| 21:34:51 | openstack | Launchpad bug 1815692 in OpenStack Compute (nova) "minimum nova-compute service version is not cached in nova-api when running under wsgi" [Low,Triaged] | |
| 21:35:24 | dansmith | ah | |
| 21:36:13 | mriedem | that would not affect the other bug on startup though because we don't call that method which uses the cache https://github.com/openstack/nova/blob/0bed18ffbb46c4f2d0ec87e64a39188c165398eb/nova/objects/service.py#L507 | |
| 21:36:47 | mriedem | but as i recall objects.Service.enable_min_version_cache() is meant for perf gains in the api lookups | |
| 21:36:49 | mriedem | after startup | |
| 21:36:51 | dansmith | I think your singleton patch looks okay | |
| 21:37:08 | dansmith | so, | |
| 21:37:11 | mriedem | i haven't looked into the functional test failures | |
| 21:37:13 | dansmith | with the sighup thing not working, | |
| 21:37:18 | dansmith | you might not want to fix the caching thing :P | |
| 21:37:41 | dansmith | that might be why it hasn't been as much of a thing.. potentially.. if people aren't sighupping but still getting the pin recalculated | |
| 21:37:57 | dansmith | although the perf impact is probably worse than just having to bump all your services fully | |
| 21:38:18 | mriedem | the sighup for nova-compute is particularly busted b/c of the privsep usage and neutron event callback handler stuff, | |
| 21:38:21 | dansmith | what a tangled mess of shit | |
| 21:38:35 | dansmith | right, but it's also going to cause anything else to do a full restart | |
| 21:38:42 | mriedem | but i wasn't sure if hup'ing the controller services was still ok because we have the cells cache for connections and disabled cells and all that | |
| 21:38:44 | dansmith | not as impactful for apis I guess | |
| 21:39:01 | dansmith | but for conductor it's probably not great either | |
| 21:39:13 | mriedem | ok so i think you're saying huping the controller services will do what you want - reload caches, but not in the graceful way we intended | |
| 21:39:30 | mriedem | b/c it's a restart | |
| 21:39:30 | dansmith | I dunno about conductor, probably not great there, | |
| 21:39:43 | mriedem | scheduler has the hup for the disabled cells i think | |
| 21:39:47 | dansmith | as I think anything currently waiting on an rpc call, or polling for state or whatever will die | |
| 21:39:49 | mriedem | and cells cache in the request context | |
| 21:40:18 | mriedem | tangled mess of shit yes | |
| 21:40:24 | dansmith | for serious | |
| 21:40:25 | mriedem | who's being depressing NOW! | |
| 21:40:33 | dansmith | o/ | |
| 21:40:42 | mriedem | maybe my depression rubs off on those that speak with me | |
| 21:40:46 | dansmith | and it's thursday, closer to friday | |
| 21:40:57 | mriedem | efried: melwitt: how are you feeling right now? | |
| 21:41:03 | dansmith | you're also the arsehole that is finding this stuff | |
| 21:41:10 | dansmith | we could just ignore it if it wasn't for you | |
| 21:43:20 | melwitt | yeah, seriously | |