| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-09-16 | |||
| 13:06:43 | efried | shilpasd: Your work on this feature is really appreciated. Please pass our compliments on to your colleagues as well. | |
| 13:08:25 | shilpasd | dansmith: stephenfin: takashin: thanks for review | |
| 13:08:42 | shilpasd | efried: sure thanks | |
| 13:13:16 | efried | stephenfin: First thing that jumps out is test_select_destination_with_pcpu_fallback_disabled, which is a test, is calling test_select_destination_with_4_3_client, which is also a test. I.e. both are going to run "simultaneously", one being a subset of the other. | |
| 13:13:27 | efried | ...which should be fine, as long as neither is doing anything global | |
| 13:14:43 | stephenfin | they don't _look_ like they're doing anything global | |
| 13:18:01 | kashyap | print domain_caps[arch][machine_type]._os.loader.enums | |
| 13:18:06 | kashyap | Oops | |
| 13:18:38 | kashyap | (Disregard that, please) | |
| 13:21:28 | kashyap | efried: Mired in parsing some XML bits and testing :D | |
| 13:21:38 | efried | suuuure | |
| 13:21:40 | kashyap | Not my day today... | |
| 13:23:02 | efried | stephenfin: I agree. I'm looking through the other tests in that class; the problem could just as easily be caused by one of *them* doing something global. | |
| 13:44:33 | mriedem | gibi: a few comments in this bug fix of yours https://review.opendev.org/#/c/666857/ | |
| 13:44:37 | stephenfin | efried: something is messing with flags | |
| 13:44:59 | efried | stephenfin: Because CONF is global mebbe? | |
| 13:45:08 | stephenfin | quite possibly, yeah | |
| 13:45:45 | stephenfin | 'CONF.workarounds.disable_fallback_pcpu_query' is intermittently 'False' despite me setting it to 'True' in the test | |
| 13:48:32 | efried | stephenfin: I can reproduce reliably locally when I skip test discovery, and reliably *not* reproduce when I let discovery happen (which runs the tests slower). So definitely racy. | |
| 13:54:30 | efried | stephenfin: Yeah, self.flags is just CONF.set_override | |
| 13:54:58 | stephenfin | and CONF is global | |
| 13:55:26 | efried | stephenfin: use oslo_config.fixture.Config | |
| 13:55:30 | stephenfin | This is hardly the first time we've got positive and negative tests for something config opt-driven though, is it? | |
| 13:56:08 | sean-k-mooney | well | |
| 13:56:24 | sean-k-mooney | you wont have two tests running at the same time in the same process | |
| 13:56:37 | sean-k-mooney | so its fine to set things with set flags | |
| 13:56:49 | sean-k-mooney | as long as you alreay set the correct state up in the test | |
| 13:56:51 | efried | sean-k-mooney: same process yes, same thread no, right? | |
| 13:56:58 | sean-k-mooney | no | |
| 13:57:09 | artom | Wait, has oslo_config.fixture.Config finally fixed the global CONF problem? I guess the fixture is not per-test, so no. | |
| 13:57:11 | sean-k-mooney | tox runes tests in multiple processes not threads | |
| 13:57:25 | stephenfin | well, stestr | |
| 13:57:57 | efried | artom: ...no, it looks like it still by default uses global CONF. So much for that idea. | |
| 13:58:10 | sean-k-mooney | yes point is each worker is tis own process that runs its own python interpreter | |
| 13:58:19 | sean-k-mooney | and only 1 test is running in each worker at a time | |
| 13:58:34 | sean-k-mooney | so test only share global state with other test that ran in that worker | |
| 13:58:41 | stephenfin | we're using ConfFixture in our base test class in nova/test.py | |
| 13:58:43 | sean-k-mooney | but only one test is running at a time | |
| 14:00:12 | stephenfin | then wtf is happening here? :-D | |
| 14:00:47 | sean-k-mooney | im just back form lunch so i can start runing it in a debugger | |
| 14:01:02 | sean-k-mooney | ye have narrorwed it down to the config option yes? | |
| 14:01:18 | stephenfin | That's what I'm seeing anyway | |
| 14:01:26 | stephenfin | It should be True but it's False instead | |
| 14:01:53 | sean-k-mooney | and ye are seeing it only when the test class is run | |
| 14:02:00 | sean-k-mooney | rather then the test directly | |
| 14:02:21 | stephenfin | yeah, I'm seeing it intermittently but efried notes that it's consistent if you run without test discovery | |
| 14:02:26 | efried | which gels with the problematic result, which is expecting from GET /a_c {normal results} and is getting {normal results + fallback results} | |
| 14:02:31 | stephenfin | so 'tox -e py27 -- -n nova/tests/unit/scheduler/test_scheduler.py' | |
| 14:03:21 | efried | stephenfin, sean-k-mooney: fwiw I'm running it from within the venv as | |
| 14:03:21 | efried | stestr run -n nova.tests.unit.scheduler.test_scheduler.SchedulerManagerTestCase | |
| 14:03:27 | efried | hitting it every time | |
| 14:03:42 | sean-k-mooney | ya i can run the full file in the debugger too although im not sure if that will show anything specifically | |
| 14:03:55 | efried | ^^ is just the one test class | |
| 14:05:22 | sean-k-mooney | yep it failed for me too | |
| 14:05:52 | mriedem | i haven't been following but is there a new gate failure? | |
| 14:05:59 | mriedem | and if so, do we have a bug and e-r query tracking it? | |
| 14:05:59 | sean-k-mooney | no | |
| 14:06:18 | sean-k-mooney | its a intermitent failure of one of the tests in the PCPU series | |
| 14:10:01 | efried | stephenfin: So I've narrowed it down, by commenting out all the tests in the suite *except* test_select_destination_with_pcpu_fallback_disabled and test_select_destination_with_pcpu_fallback I still get the repro; commenting out either of those and I'm fine. | |
| 14:10:18 | efried | I also factored out the 4_3 thing so the former ^ only runs the one test | |
| 14:10:38 | efried | I also commented out the self.flags in the latter ^ because it's setting the default -- and still get the repro | |
| 14:10:53 | efried | so those two tests are banging on each other somehow. | |
| 14:11:59 | sean-k-mooney | why are we calling a test method directly by the way instead fo factoring out the common code into a helper method | |
| 14:12:54 | efried | sean-k-mooney: that was the first thing I mentioned. But it doesn't make a difference, cause it's also the first thing I tried :P | |
| 14:13:06 | stephenfin | sean-k-mooney: Because the theory was that the test end result and assertions should be identical under both circumstances | |
| 14:13:16 | stephenfin | ditto | |
| 14:13:44 | sean-k-mooney | yes but i was wonddering if we where sharing mocks by not doing it | |
| 14:14:15 | stephenfin | possibly. I tried reseting the 'select_destinations' mock to no avail | |
| 14:15:14 | artom | Why does discovery affect it, though? Discovery doesn't run any tests, does it? | |
| 14:15:24 | stephenfin | I think it's just ordering | |
| 14:15:27 | efried | no, it just makes the tests run much more quickly | |
| 14:15:28 | efried | yeah | |
| 14:15:57 | artom | Ah, so a timing issue | |
| 14:15:58 | efried | it seems as though discovery even slows down the running of the tests themselves | |
| 14:16:00 | efried | yes | |
| 14:16:14 | sean-k-mooney | well its not a timeing issue when we are leaking shared state | |
| 14:16:20 | artom | It causes thing to not run at the same time | |
| 14:16:26 | sean-k-mooney | no | |
| 14:16:34 | sean-k-mooney | but it may change the order | |
| 14:16:36 | efried | I would have thought it would do all discovery, come up with a list of tests, and then run 'em, and by the time you got to that last thing it was the same as if you did no discovery. But clearly that's not how it's happening. | |
| 14:16:42 | efried | yeah, or possibly ordering I guess | |
| 14:16:51 | stephenfin | efried: I've noticed that all the other mock assertions pass too | |
| 14:17:14 | stephenfin | so maybe it's not the global conf :-\ | |
| 14:18:25 | artom | stephenfin, but... you said you've observed an option being False when it should be True... | |
| 14:18:28 | efried | stephenfin: waitwait | |
| 14:18:39 | efried | you're saying GET /a_c is called the appropriate number of times?? | |
| 14:19:05 | stephenfin | That's what I'm seeing. Put the 'select_destinations.assert_called_once_with' to the end | |
| 14:19:13 | stephenfin | in select_destinations.assert_called_once_with | |
| 14:19:19 | stephenfin | sorry, test_select_destination_with_4_3_client | |
| 14:19:51 | sean-k-mooney | i have it open in the debuger now so ill check | |
| 14:19:52 | stephenfin | assert_called_once_with checks that things are called exactly once, right/ | |
| 14:20:05 | sean-k-mooney | yes its called once | |
| 14:21:24 | sean-k-mooney | stephenfin: it check its called exactly once and has the correct args | |
| 14:21:28 | sean-k-mooney | so yes | |
| 14:21:53 | efried | I put a call_count assertion just in case | |
| 14:23:56 | stephenfin | moving the mocks inline and using context managers instead of function decorators doesn't help | |
| 14:24:47 | sean-k-mooney | if i put the select_destinations.assert_called_once_with( call at the end all the rest pass | |
| 14:27:43 | sean-k-mooney | its failing in assert_called_with when its comparing the args | |
| 14:32:46 | stephenfin | efried, sean-k-mooney: got it | |
| 14:32:50 | efried | tell | |