| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2023-09-11 | |||
| 09:42:18 | sean-k-mooney | "" | |
| 09:42:35 | sean-k-mooney | ok so they reverted that | |
| 09:42:42 | elodilles | yepp | |
| 09:43:14 | sean-k-mooney | so im still trying to figure out why its failing as none of the failing test cases test/use oslo log fucntionality | |
| 09:43:24 | sean-k-mooney | i think this is actully breakign due to privsep somehosw | |
| 09:44:09 | elodilles | anyway, this needs to be sorted out together with oslo team, as Bobcat final release is in 3 weeks | |
| 09:44:53 | elodilles | I'd say if there is an easy fix in nova, then we should add that fix in nova ASAP, because it's easier then to invalidate a release | |
| 09:45:13 | elodilles | sean-k-mooney: thanks for looking into the issue | |
| 09:46:05 | sean-k-mooney | oh https://github.com/openstack/oslo.log/compare/5.2.0...5.3.0 is not in revers chronalogical order | |
| 09:46:22 | sean-k-mooney | so ya i see teh revert i was confued by that | |
| 09:47:00 | elodilles | ++ | |
| 09:47:44 | sean-k-mooney | im not seeing any change there that could cause this so i think it must be form a change in privsep | |
| 09:47:49 | sean-k-mooney | well | |
| 09:47:53 | sean-k-mooney | we do actully log her | |
| 09:47:57 | sean-k-mooney | https://github.com/openstack/nova/blob/master/nova/privsep/utils.py#L43-L90 | |
| 09:48:40 | sean-k-mooney | in the failing test we are makign this raise an error https://github.com/openstack/nova/blob/master/nova/privsep/utils.py#L57 | |
| 09:49:11 | sean-k-mooney | specificaly value error | |
| 09:49:20 | sean-k-mooney | and we are expecting to take this path https://github.com/openstack/nova/blob/master/nova/privsep/utils.py#L76-L78 | |
| 09:50:28 | sean-k-mooney | we mock os.write and assert its not called here https://github.com/openstack/nova/blob/master/nova/privsep/utils.py#L61 | |
| 09:50:39 | sean-k-mooney | sorry off by one | |
| 09:50:41 | sean-k-mooney | https://github.com/openstack/nova/blob/master/nova/privsep/utils.py#L62 | |
| 09:51:21 | sean-k-mooney | im wondering if the LOG.error in the excption block is somehow counting as a call to os.write | |
| 09:51:51 | sean-k-mooney | in the unit test we shoudl be using a stringIO buffer for logging in the test fixture | |
| 09:52:03 | sean-k-mooney | so there shoudl not be aby write calls to stdout or a file | |
| 09:52:36 | sean-k-mooney | ill see if i can repoduce it locally but it does not really make sesne why this would pass on 5.2.0 and not 5.3.0 | |
| 09:53:01 | frickler | sorry, was away for a bit. in general, new openstack library releases are not affected by requirements freeze I think. in particular if merging them is delayed by other projects | |
| 09:54:12 | frickler | so oslo.log 5.3.0 is part of the bobcat release and thus should make it into u-c as well if possible | |
| 09:55:11 | frickler | ah, elodilles said that in between already | |
| 10:04:09 | sean-k-mooney | frickler: the final release is ment to happen before FF | |
| 10:04:21 | sean-k-mooney | that why we have the non client freeze before it | |
| 10:04:50 | sean-k-mooney | so we do not expect to have any new non-client release in uc between FF and RC-1 unless its an RC-1 fix | |
| 10:05:31 | sean-k-mooney | it looks like the release was actully done 13 days ago | |
| 10:05:40 | sean-k-mooney | so that would have been before FF | |
| 10:05:57 | frickler | yes, it is just the u-c bump that is lagging | |
| 10:06:37 | sean-k-mooney | right which is not good because that kidn of defeats the reason for the eailer releas | |
| 10:06:57 | sean-k-mooney | but i guess in this case it just would have been better to highlihgt this earlier | |
| 10:07:03 | sean-k-mooney | i.e. that it was not passing | |
| 10:08:29 | sean-k-mooney | im running the tests with the older release not and then ill manually unpin and see if this repoduces for me locally | |
| 10:08:30 | frickler | yes, handling by the requirements team could be improved if they had more participants I guess. it also isn't helped by the CI being unstable in general. I'm just trying to fill in some of the gaps where I can | |
| 10:10:21 | sean-k-mooney | so locally passes with 5.2.0 and fails with 5.3.0 | |
| 10:10:29 | sean-k-mooney | so thats a good start | |
| 10:11:13 | sean-k-mooney | looks like the same error too | |
| 10:11:35 | sean-k-mooney | although for some reason my tox execution seams to be hanging... | |
| 10:16:17 | sean-k-mooney | oh right the other test is a timeout exception | |
| 10:16:21 | sean-k-mooney | so it was just waitign on that | |
| 10:45:29 | opendevreview | Merged openstack/python-novaclient stable/2023.2: Update .gitreview for stable/2023.2 https://review.opendev.org/c/openstack/python-novaclient/+/894074 | |
| 11:07:06 | sean-k-mooney | this is kind of insane | |
| 11:07:19 | sean-k-mooney | apprently this LOG.ERROR is causign the test to fail | |
| 11:07:21 | sean-k-mooney | https://github.com/openstack/nova/blob/master/nova/privsep/utils.py#L77C13-L78C62 | |
| 11:08:05 | sean-k-mooney | this passes https://paste.opendev.org/show/bUyh4M9k01rrYaP58223/ | |
| 11:08:46 | sean-k-mooney | but https://paste.opendev.org/show/b4wfwcpSB6XdjPZzC5UN/ fails | |
| 11:09:11 | sean-k-mooney | but the error is | |
| 11:09:13 | sean-k-mooney | AssertionError: Expected 'write' to not have been called. Called 1 times. | |
| 11:09:15 | sean-k-mooney | Calls: [call(7, b'X')]. | |
| 11:10:08 | sean-k-mooney | the commented out code | |
| 11:10:11 | sean-k-mooney | # m.write(b"x" * align_size) | |
| 11:10:13 | sean-k-mooney | # os.write(fd, m) | |
| 11:10:28 | sean-k-mooney | woudl write X to fd 7 | |
| 11:10:35 | sean-k-mooney | but its commeted out... | |
| 11:10:47 | sean-k-mooney | and the log message is not writng that | |
| 11:30:06 | sean-k-mooney | sothere is somehting funky happening https://github.com/openstack/oslo.log/compare/5.3.0...5.2.0 and https://github.com/openstack/oslo.log/compare/5.2.0...5.3.0 | |
| 11:30:17 | sean-k-mooney | shoudl not both show patches but they do | |
| 11:37:20 | elodilles | sean-k-mooney: now that i'm looking at git tree it shows that we had some issue with oslo.log at antelope release, thus reverted the two patches, but we did it on stable/2023.1 branch and not on master | |
| 11:39:25 | sean-k-mooney | ack | |
| 11:39:35 | sean-k-mooney | perhaps i shoudl be diffeint agaisnt a diffent base | |
| 11:40:05 | sean-k-mooney | the failure is definatly comign form the LOG.error call | |
| 11:40:15 | sean-k-mooney | but i cant see any patch that would casue this in those diffes | |
| 11:40:27 | elodilles | yes, 5.1.0..5.3.0, but it still not shows the reverts that we only merged on stable/2023.1 :/ | |
| 11:41:35 | elodilles | there are 3 patches reverted in 5.2.0 | |
| 11:41:45 | sean-k-mooney | just so we are on the same page https://paste.opendev.org/show/bHorJ0sp6UTAKfu2EbJ2/ passes | |
| 11:42:03 | sean-k-mooney | its the LOG.error on line 34 | |
| 11:42:22 | sean-k-mooney | that is causing the issue but the message it is loging and the assert that is fialing do not make sense | |
| 11:43:42 | sean-k-mooney | no matter what i log it causes Calls: [call(7, b'X')] on os.write | |
| 11:45:30 | elodilles | sean-k-mooney: these were reverted on 5.2.0, but not in master (5.3.0): https://paste.opendev.org/show/bRU8ommJhreoVpdiWMRV/ | |
| 11:45:46 | elodilles | one of them has to be related to the issue | |
| 11:46:51 | sean-k-mooney | so the eventlet fix was added and removed fith | |
| 11:46:54 | sean-k-mooney | *right | |
| 11:47:19 | sean-k-mooney | im going to cloen oslo.log and pip install -e it into the env | |
| 11:47:25 | sean-k-mooney | and i guess do a biset effectivly | |
| 11:48:51 | frickler | so this whole issue is 6 months old and got successfully ignored? cool | |
| 11:49:42 | sean-k-mooney | no idea really. its only causing two test to fail | |
| 11:49:51 | sean-k-mooney | so i dont think its actully breaking real code | |
| 11:50:15 | sean-k-mooney | however im not parcarlly happy with just modifying the test without understadnign why this is breakign | |
| 11:50:27 | sean-k-mooney | as it really not obvious why this is happeining | |
| 11:50:58 | sean-k-mooney | and looking at the patch delta i woudl not expect this type of change between 5.2.0 and 5.3.0 | |
| 11:53:25 | elodilles | stephenfin: do you have any idea what could be a solution for this oslo.log issue? ^^^ | |
| 11:56:34 | sean-k-mooney | so its broken by 94b9dc3 | |
| 11:56:40 | frickler | sean-k-mooney: 5.2.0 is a bugfix release only done on stable/2023.1, 5.1.0 is the initial release for 2023.1 | |
| 11:56:51 | sean-k-mooney | https://github.com/openstack/oslo.log/commit/94b9dc32ec1f52a582adbd97fe2847f7c87d6c17 | |
| 11:56:52 | elodilles | yepp | |
| 11:57:08 | frickler | so 5.1.0..5.3.0 gives a better idea of what happened in master. though iiuc the issue is in 5.0.0..5.1.0 | |
| 11:58:29 | frickler | 94b9dc3 is 5.0.1, ack | |
| 11:59:20 | sean-k-mooney | so with that calls to LOG.error are internally using os.write | |
| 11:59:32 | sean-k-mooney | presumably its realted to the lock its taking | |
| 11:59:44 | sean-k-mooney | here https://github.com/openstack/oslo.log/commit/94b9dc32ec1f52a582adbd97fe2847f7c87d6c17#diff-2c76d41c287653560e6e84f39ce877b4f9ba33c7b36db17194e7435cd54adfb0R41 | |
| 12:00:58 | sean-k-mooney | its this call on release | |
| 12:01:04 | sean-k-mooney | https://github.com/openstack/oslo.log/commit/94b9dc32ec1f52a582adbd97fe2847f7c87d6c17#diff-2c76d41c287653560e6e84f39ce877b4f9ba33c7b36db17194e7435cd54adfb0R108 | |
| 12:01:09 | sean-k-mooney | line 108 | |
| 12:01:19 | sean-k-mooney | that is causing teh test failure sepcifically | |
| 12:01:50 | sean-k-mooney | the next commit maks this conditionaly | |