| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2025-03-25 | |||
| 14:08:37 | dansmith | glance functional tests are sort of similar.. really really hard to get the backend logs when there's a failure | |
| 14:08:39 | dansmith | super annoying | |
| 14:14:39 | gibi | I agree | |
| 14:16:48 | sean-k-mooney | i was going to suggest the same OS_DEBUG=1 i confirmed it is allowed in the tox config so its not that either | |
| 14:18:08 | sean-k-mooney | its usign the normal log fixtures but it also has 2 addtional ones for error and warning | |
| 14:18:10 | sean-k-mooney | https://github.com/openstack/placement/blob/master/placement/tests/functional/base.py#L54-L58 | |
| 14:18:22 | sean-k-mooney | so i think its those last two that are the problem | |
| 14:18:31 | dansmith | yeah, I'm about to just repro the gabbit that is failing in python so I can effing see the problem | |
| 14:18:49 | sean-k-mooney | i woudl ty comemntign out lines 57 and 58 | |
| 14:18:57 | sean-k-mooney | and see fi it woks with os_debug then | |
| 14:19:41 | dansmith | already tried :) | |
| 14:20:46 | sean-k-mooney | well you can do the tried and true Raise RuntimeError instead of logging | |
| 14:22:27 | dansmith | I have no idea where it's failing | |
| 14:22:33 | sean-k-mooney | https://github.com/openstack/placement/blob/master/placement/tests/functional/fixtures/capture.py#L40-L62 | |
| 14:22:35 | dansmith | it's a 500, which should be logging lots | |
| 14:24:38 | sean-k-mooney | oh gabbit also has its own fixtures with its own logging config. it does include that however | |
| 14:24:47 | sean-k-mooney | https://github.com/openstack/placement/blob/master/placement/tests/functional/fixtures/gabbits.py#L62 | |
| 14:24:57 | dansmith | there are multiple layers of log interception in placement, and also in gabbi yeah | |
| 14:25:16 | dansmith | I'm wondering if gabbi has changed in some way and left placement stuck | |
| 14:25:39 | dansmith | to be clear, I've tried to mangle that capture module and I'm not sure it's ever even getting hit | |
| 14:25:46 | dansmith | I can define error, warning, etc on there and raise and nothing changes | |
| 14:26:01 | dansmith | not sure if that's because it ends up with another nameless 500 or what | |
| 14:27:30 | sean-k-mooney | well if you are looging and its intercepted it should show up in one fo those fixtures | |
| 14:27:48 | dansmith | to be clear, I'm not logging | |
| 14:28:00 | dansmith | there's a gabbit test that now fails with 500 after a change I made | |
| 14:28:08 | dansmith | and I'm trying to figure out what the 500 is | |
| 14:28:15 | sean-k-mooney | oh you want ot see that ok | |
| 14:28:23 | dansmith | but I agree, it should be going through that fixture | |
| 14:28:58 | sean-k-mooney | so it has to be realted to this block https://github.com/openstack/placement/blob/master/placement/tests/functional/fixtures/gabbits.py#L62-L71 | |
| 14:30:09 | dansmith | I mean, you'd think, but there are similar fixtures also in functional/base | |
| 14:30:17 | dansmith | and in gabbi itself | |
| 14:31:04 | sean-k-mooney | oh you think that the fact we are inheriting form the gabbit testcase might be altering the behavior | |
| 14:31:16 | sean-k-mooney | looking at git blame https://github.com/openstack/placement/commit/fcd1e538d9b7d315cb3f74c83f1a9e4ddcab180e | |
| 14:31:41 | sean-k-mooney | it same like there was a lot of log output in the past and they added thsi handelign ot silance some of that | |
| 14:31:58 | dansmith | I removed all those fixture setups in gabbits.py and no change | |
| 14:32:25 | dansmith | right, I'm sure it's the attempt to make it pretty, but it has made it completely un-debuggable, AFAICT | |
| 14:32:28 | sean-k-mooney | i proably shoudl be doing somethign else bug you peaked my interest | |
| 14:32:44 | sean-k-mooney | do you have a patch i can pully or aplly and see if i can replicate it | |
| 14:33:18 | dansmith | I can push it up | |
| 14:34:44 | opendevreview | Dan Smith proposed openstack/placement master: Reproduce bug 2104040: allocate in over-capacity https://review.opendev.org/c/openstack/placement/+/945464 | |
| 14:34:45 | opendevreview | Dan Smith proposed openstack/placement master: Fix placement allocate while over-capacity https://review.opendev.org/c/openstack/placement/+/945465 | |
| 14:34:54 | dansmith | sean-k-mooney: ^ | |
| 14:35:09 | sean-k-mooney | the secodn one is causign the 500 ya | |
| 14:35:16 | dansmith | maybe the actual thing failing will get hit by a tempest test and I can see what the effing problem is :) | |
| 14:35:17 | dansmith | yeah | |
| 14:36:49 | sean-k-mooney | well placmeent does not use eventlet so in theory i can also run this under a debugger in vscoded and set a breakpoint | |
| 14:37:14 | sean-k-mooney | i have never tried that with placment but i have got that to work wiht some of watchers unit tests | |
| 14:37:19 | dansmith | if I knew where to set a breakpoint I could do the same :) | |
| 14:37:44 | sean-k-mooney | you can make the debugger tirgger on uncaught excetpions | |
| 14:38:18 | sean-k-mooney | im going ot make sure i can repoduce the fialure first and then ill try something more fancy | |
| 14:39:48 | dansmith | thanks, maybe I've got tunnel vision on something | |
| 14:44:23 | sean-k-mooney | ... we still have not merget the patch to move form psycopg2 to psycopg2-binary... | |
| 14:44:32 | sean-k-mooney | oh we didnt propose that ot placment | |
| 14:44:36 | sean-k-mooney | ill fix that later | |
| 14:45:10 | sean-k-mooney | if we use psycopg2-binary instead we dont need the postgress development headers to be able to compile it | |
| 14:47:41 | sean-k-mooney | dansmith: so i ran the functional tests and everything passed | |
| 14:47:52 | sean-k-mooney | oh nevermind | |
| 14:47:59 | sean-k-mooney | that with master i have not applied you change yet | |
| 14:48:39 | sean-k-mooney | i did see "TransactionFactory already started, not reconfiguring." pirnted once or twice which is a bit suss but it does nto seam to be breaking anything | |
| 14:49:07 | dansmith | master passes for me too :) | |
| 14:49:40 | dansmith | I think I've just guessed the thing it's failing on by trial and error, which is good, but it's like debugging in the dark | |
| 14:50:35 | sean-k-mooney | so i have output | |
| 14:50:41 | sean-k-mooney | and two failed testcases | |
| 14:51:01 | sean-k-mooney | https://paste.opendev.org/show/baZsKMeiO9mOxyGz2OlY/ | |
| 14:51:11 | dansmith | ...right | |
| 14:51:15 | dansmith | that's just gabbit output | |
| 14:51:30 | dansmith | not the logging from the wsgi app to show you where the 500 was | |
| 14:51:38 | sean-k-mooney | ah you want the api logs form the service right | |
| 14:51:51 | dansmith | yeah, so I can see, you know, the *actual* problem | |
| 14:53:15 | sean-k-mooney | right well now that i know which tests are failing i can see if i can get more output sicn ei an just target those specific tests | |
| 15:05:29 | Uggla | sean-k-mooney, do you think we should have a cross team nova-watcher session at the PTG ? | |
| 15:05:45 | sean-k-mooney | sigh... the way we dynmically load teh gabit tst means that they are not discoverd wehn we use pytest and the way we alias the global fixtures module with our own breaks unittests discoveray | |
| 15:06:59 | sean-k-mooney | Uggla: am we could the topics i wanted to raise are not only relvent to watcher but it does not need to be super formal | |
| 15:07:05 | dansmith | sean-k-mooney: yep, already tried that, but you can use testtools directly, just not for a specific test. you have to run all the gabbit tests | |
| 15:07:46 | sean-k-mooney | did you try the stestr pdb supprot? | |
| 15:10:15 | sean-k-mooney | ... AttributeError: module 'placement.tests.functional.test_api' has no attribute 'allocations-bug-1778743_post_multiple_allocations' | |
| 15:10:22 | sean-k-mooney | right | |
| 15:11:09 | Uggla | sean-k-mooney, ok so I will not create a specific time slot only for watcher and will "distribute" the topic in the agenda where it fits best. Is that ok ? | |
| 15:11:26 | sean-k-mooney | sounds good | |
| 15:12:21 | sean-k-mooney | dansmith: so passing --pdb to stestr didnt help either how fun | |
| 15:13:32 | dansmith | lovely | |
| 15:16:14 | opendevreview | Dan Smith proposed openstack/placement master: Fix placement allocate while over-capacity https://review.opendev.org/c/openstack/placement/+/945465 | |
| 15:16:37 | sean-k-mooney | dansmith: https://github.com/cdent/gabbi/commit/2469b1617fde2ee62f42ef48fc38a7d075c1dd62#diff-af026a8f8ce5b1d6bf2c2b9a33c71ba0566feb828ca0fbc8ec4f3970c2835c75 | |
| 15:16:46 | sean-k-mooney | appreently you can mark a test as verbose | |
| 15:17:14 | dansmith | and that lets logs go? | |
| 15:19:20 | sean-k-mooney | not exactly https://paste.opendev.org/show/bI2SFFiDmfx51VXu7CrD/ | |
| 15:19:36 | sean-k-mooney | you do get more output | |
| 15:19:54 | dansmith | unhelpful output | |
| 15:20:19 | sean-k-mooney | its jsut increasing the verbosity of the client | |
| 15:26:56 | dansmith | yeah | |
| 15:33:59 | sean-k-mooney | ok i have logs but i need to change code | |
| 15:34:08 | sean-k-mooney | ill make this configuable in a env var | |
| 15:34:46 | sean-k-mooney | tldr set this to false https://github.com/openstack/placement/blob/master/placement/tests/functional/fixtures/capture.py#L55 | |
| 15:35:12 | dansmith | WAT | |
| 15:35:16 | dansmith | set to false? | |
| 15:35:35 | sean-k-mooney | yep to turn off the log capture and allow it to print to stderr | |
| 15:35:36 | dansmith | I have commented out the usage of that thing entirely and I still don't get logs | |
| 15:36:09 | dansmith | do you also have to disable the stdio capture? | |
| 15:36:10 | sean-k-mooney | i also invoked it liek this wiht a few other changes | |
| 15:36:12 | sean-k-mooney | OS_DEBUG=1 OS_LOG_CAPTURE=1 tox -e functional -- --failing | |