| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2023-01-18 | |||
| 16:26:27 | gibi | bauzas: if I'm right L90 in your modification wont return https://review.opendev.org/c/openstack/tempest/+/870913/2/tempest/api/compute/admin/test_aaa_volume.py#90 | |
| 16:26:59 | bauzas | gibi: hmm? | |
| 16:27:05 | bauzas | https://docs.openstack.org/oslo.utils/ocata/examples/timeutils.html#using-a-stopwatch-as-a-context-manager | |
| 16:27:08 | gibi | bauzas: OMM will kill the process in the midle | |
| 16:27:19 | gibi | OOM | |
| 16:27:28 | bauzas | gibi: no, the test is run before | |
| 16:27:33 | dansmith | this also means anyone using tempest with a real image (like for verification) will be eating a ton of data | |
| 16:27:37 | bauzas | that's still using aaa | |
| 16:27:48 | gibi | calling _create_image_with_custom_property will trigger the OOM | |
| 16:28:03 | bauzas | gibi: it wasn't the case in the first revision | |
| 16:28:20 | bauzas | we waited for 180secs but eventually we didn't got a kill | |
| 16:28:59 | gibi | hm, maybe at that run the image fit into memory | |
| 16:29:28 | bauzas | https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_362/870924/2/check/nova-ceph-multistore/3626391/testr_results.html | |
| 16:29:50 | bauzas | gibi: yeah, because the test is called firstly | |
| 16:29:59 | gibi | anyhow dansmith if you look into fixing it then I will propose to disable this test in tempest with a @skip decorator as it is probably dangerous to run in any job | |
| 16:30:07 | dansmith | yeah, do it | |
| 16:30:10 | gibi | ack | |
| 16:30:18 | gibi | bauzas: ahh yeah, that helps to fit | |
| 16:30:28 | dansmith | I'm still stacking, had to start over because horizon seems broken :/ | |
| 16:30:39 | dansmith | 2023 is off to a *great* start | |
| 16:31:08 | bauzas | gibi: that said, I wonder why this test was fine since like 10 months before | |
| 16:31:13 | gibi | my local tox -e functional-py310 env produces strange failures (>1000 failed test on master) so yeah it is *great* :D | |
| 16:31:27 | dansmith | bauzas: I recently increased the size of the image used on the ceph job from 16MB to 1G | |
| 16:31:32 | dansmith | but that was in like november or so | |
| 16:31:39 | dansmith | so I'm pretty surprised we've been holding on this long | |
| 16:31:54 | dansmith | probably because that memory never gets touched again and just gets swapped out | |
| 16:32:56 | sean-k-mooney | the gate was pretty ok after you went on pto in the start od december | |
| 16:33:06 | sean-k-mooney | so i dont think its related to using the 1G image | |
| 16:33:09 | dansmith | sean-k-mooney: I'm happy to leave if that's what helps | |
| 16:33:30 | dansmith | sean-k-mooney: this job crashing with OOM seems clearly related as the job eats the 1g image and ... swells to 1g before it goes boom | |
| 16:33:45 | dansmith | s/job/test worker/ | |
| 16:33:52 | sean-k-mooney | ok do we know why its only happening now or did we get lucky beofre | |
| 16:34:02 | gibi | maybe something else grown in memory usage recently a bit and pushing the overall worker VM over the line | |
| 16:34:27 | gibi | sean-k-mooney: as bauzas shown if your run this test earlier in the job then it still passes | |
| 16:34:32 | dansmith | sean-k-mooney: read the scrollback :) | |
| 16:34:35 | sean-k-mooney | ya well ok we could revert back to 512 mb and see if it grows by 512mb | |
| 16:34:46 | sean-k-mooney | i was just starting too ya | |
| 16:34:47 | dansmith | sean-k-mooney: gibi identified a test that reads the whole image into memory | |
| 16:34:58 | bauzas | gibi: dansmith: added Tempest and glance to the bug report | |
| 16:34:58 | sean-k-mooney | oh ok | |
| 16:35:10 | sean-k-mooney | so fix that test or revert i assume fix the test to not do that | |
| 16:35:21 | sean-k-mooney | or exilcitly use a small image in that test | |
| 16:35:28 | bauzas | sean-k-mooney: I have a change that will tell us how much memory it takes https://review.opendev.org/c/openstack/tempest/+/870913/2/tempest/api/compute/admin/test_aaa_volume.py#90 | |
| 16:35:37 | dansmith | no, the test is old there's nothing to revert | |
| 16:35:41 | dansmith | we need to fix the test | |
| 16:36:31 | bauzas | dansmith: I think we have now an issue because we call more tests | |
| 16:36:34 | sean-k-mooney | by revert i ment your image change but the test is clearly not writen as we woudl like | |
| 16:36:43 | sean-k-mooney | i.e. it should not break with a bix image | |
| 16:36:50 | sean-k-mooney | *big | |
| 16:36:57 | bauzas | while it was working fine before, now the memory is too large | |
| 16:36:58 | sean-k-mooney | like downstream i know we use rhel images in some cases | |
| 16:37:11 | sean-k-mooney | and those are just under a gig too like 700mb | |
| 16:37:35 | dansmith | the images client in tempest already chunks the upload, it just does it from a fixed size buffer, so it just needs to be smarter | |
| 16:37:37 | bauzas | sean-k-mooney: again, we'll know how much memory creates this test with my new CI job | |
| 16:38:03 | sean-k-mooney | bauzas: just got back to this point in scrolback | |
| 16:38:07 | sean-k-mooney | bauzas: ack | |
| 16:38:22 | dansmith | the large image was specifically to flush out things like this, so I don't think going back to a small image gets us anything useful | |
| 16:38:26 | bauzas | anyway, this is a guess | |
| 16:38:38 | bauzas | nothing was changed in this module since Feb 22 | |
| 16:38:39 | dansmith | if anything, it makes me think we can make it larger as this might have been the OOM limit I was running into with 2G | |
| 16:38:40 | sean-k-mooney | dansmith: i agree | |
| 16:39:03 | bauzas | https://github.com/openstack/tempest/blob/master/tempest/api/compute/admin/test_volume.py | |
| 16:39:20 | sean-k-mooney | dansmith: the trade of is we only have 80G of disk space in ci | |
| 16:39:33 | sean-k-mooney | so back to 2G perhaps 20G proably not | |
| 16:39:34 | bauzas | oh wait | |
| 16:39:36 | dansmith | I understand, disk space is not the issue though | |
| 16:39:40 | bauzas | maybe we change the image ref | |
| 16:40:19 | opendevreview | Kashyap Chamarthy proposed openstack/nova master: libvirt: At start-up allow skiping compareCPU() with a workaround https://review.opendev.org/c/openstack/nova/+/870794 | |
| 16:41:00 | kashyap | Duh, forgot to commit 2 files | |
| 16:41:20 | opendevreview | Kashyap Chamarthy proposed openstack/nova master: libvirt: At start-up allow skiping compareCPU() with a workaround https://review.opendev.org/c/openstack/nova/+/870794 | |
| 16:45:41 | bauzas | https://github.com/openstack/devstack/blob/master/lib/tempest#L213-L220 | |
| 16:45:43 | bauzas | hmmmm | |
| 16:46:14 | gibi | propsed the skip for this test https://review.opendev.org/c/openstack/tempest/+/870974 I checked no other test using the _create_image_with_custom_property util function | |
| 16:46:29 | bauzas | 2023-01-18 11:54:33.763321 | controller | ++ lib/tempest:get_active_images:155 : '[' cirros-raw = cirros-0.5.2-x86_64-disk ']' | |
| 16:46:37 | bauzas | https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_362/870924/2/check/nova-ceph-multistore/3626391/job-output.txt | |
| 16:46:46 | bauzas | we only get the cirros image | |
| 16:46:53 | bauzas | shouldn't be that large | |
| 16:48:22 | dansmith | bauzas: you understand that the ceph job uses a 1G cirros image right? | |
| 16:49:37 | bauzas | Jan 18 11:57:14.947333 np0032776548 glance-api[110229]: DEBUG glance.image_cache [None req-76dfbfc9-8d31-4a47-a529-e95d8077cfc0 tempest-AttachSCSIVolumeTestJSON-1393201534 tempest-AttachSCSIVolumeTestJSON-1393201534-project-admin] Tee'ing image '0bc12eec-2802-48e8-bedf-0931be582d19' into cache {{(pid=110229) get_caching_iter /opt/stack/glance/glance/image_cache/__init__.py:343}} | |
| 16:49:49 | bauzas | dansmith: oh sorry no, wasn't knowing | |
| 16:49:58 | gibi | 950MB image is downloaded in my case | |
| 16:50:10 | dansmith | bauzas: [08:31:27] <dansmith> bauzas: I recently increased the size of the image used on the ceph job from 16MB to 1G | |
| 16:50:17 | bauzas | missed that line | |
| 16:50:23 | dansmith | :) | |
| 16:50:53 | bauzas | ok, so we know that we cache 1GB in memory | |
| 16:50:57 | gibi | te test is nice as it get the image metadata first so in the log there is a "size": 996147200 before the data is downloaded | |
| 16:51:24 | bauzas | gibi: I'm waiting for my test job to return but I guess we'll see a size of 1GB in memory for that variable | |
| 16:52:29 | bauzas | dansmith: about your question (why do we trigger now the kill and not earlier), my guess is that we were just below the line | |
| 16:52:34 | opendevreview | Balazs Gibizer proposed openstack/nova master: DNM: Test that OOM triggering test is skipped https://review.opendev.org/c/openstack/nova/+/870950 | |
| 16:53:34 | dansmith | bauzas: yeah, like I said, we're probably just swapping it all and never touching it again, so pressure is high and we're close to the edge :) | |
| 16:53:45 | bauzas | one way to alleviate this issue would be to make sure we run that greedy test into a specific test runner worker | |
| 16:54:06 | opendevreview | Aaron S proposed openstack/nova master: Add further workaround features for qemu_monitor_announce_self https://review.opendev.org/c/openstack/nova/+/867324 | |
| 16:54:10 | bauzas | https://stestr.readthedocs.io/en/latest/MANUAL.html#test-scheduling | |
| 16:54:29 | bauzas | tempest exposes the worker configs from stestr | |
| 16:54:29 | gibi | bauzas: we just shouldn't load the whole image data in memory at once | |
| 16:54:57 | gibi | as in general image size can be way bigger than memory size | |
| 16:55:10 | bauzas | gibi: that's true | |
| 16:55:20 | bauzas | caching the metadata seems ok to me | |
| 16:55:34 | bauzas | caching the data itself seems unnecessary | |
| 16:55:44 | bauzas | unless you want to compare bytes per bytes | |