| gmaan | dansmith: i checked/tested it, it is same reason why you are not seeing in-progress task in log because of the order of RPC server wait and manager shutdown. rpcserver.wait <it waits and finishes the stop_instance> -> manager.graceful_shutdown() <there is no task to log> this is log example https://pastebin.com/yj96YiRJ | 02:02 |
|---|---|---|
| gmaan | and with https://review.opendev.org/c/openstack/nova/+/996583, the order is rpcserver.stop <stop any new request> -> manager.graceful_shutdown() <it logs all in-progress tasks> -> rpcserver.wait() <continue waiting for first RPC server tasks to finish> . This is log example with this change and you can see the proper in-progress task logging https://pastebin.com/q0Mm9bNF | 02:03 |
| gmaan | Aug 11 01:28:44 ubuntu-resolute nova-compute[289050]: INFO nova.manager [-] Graceful shutdown initiated with 1 in-progress tasks: stop_instance(instance=c4b95ab0-1098-45a9-b03e-7139e1ce5bfc, request_id=req-9746ce32-bcb0-4913-8861-b1499d6abfd6, elapsed=8.216098441998838) | 02:04 |
| opendevreview | Takashi Kajinami proposed openstack/nova master: Stub kernel support check of AMD-SEV in tests https://review.opendev.org/c/openstack/nova/+/999780 | 02:04 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Task tracking mechanism for graceful shutdown https://review.opendev.org/c/openstack/nova/+/996299 | 02:06 |
| gmaan | dansmith: ^^ i added the exact logs checks in the tests | 02:07 |
| gmaan | dansmith: This is a better example where I started 1 start, 2 stop instance operations. It logs all in-progress at start, logs as soon as any task is completed, and keeps logging overall progress every 10 sec; at the end, it summarizes the number of completed and failed tasks. https://pastebin.com/3fLsiMwG | 02:47 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Task tracking mechanism for graceful shutdown https://review.opendev.org/c/openstack/nova/+/996299 | 03:50 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Track and log the main RPC server in-progress task https://review.opendev.org/c/openstack/nova/+/996583 | 04:14 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Unify the thread poool executors into a central factory https://review.opendev.org/c/openstack/nova/+/998571 | 04:14 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Shutdown thread pool executors during service shutdown https://review.opendev.org/c/openstack/nova/+/1000211 | 04:14 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Add doc and release notes for the graceful shutdown task tracking https://review.opendev.org/c/openstack/nova/+/997141 | 04:15 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Task tracking mechanism for graceful shutdown https://review.opendev.org/c/openstack/nova/+/996299 | 04:27 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Track and log the main RPC server in-progress task https://review.opendev.org/c/openstack/nova/+/996583 | 04:27 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Unify the thread poool executors into a central factory https://review.opendev.org/c/openstack/nova/+/998571 | 04:27 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Shutdown thread pool executors during service shutdown https://review.opendev.org/c/openstack/nova/+/1000211 | 04:27 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Add doc and release notes for the graceful shutdown task tracking https://review.opendev.org/c/openstack/nova/+/997141 | 04:27 |
| opendevreview | Kubilay Kaptanoglu proposed openstack/nova master: Fix simple-tenant-usage state schema for deleted instances https://review.opendev.org/c/openstack/nova/+/1000415 | 08:09 |
| *** mhen_ is now known as mhen | 10:36 | |
| opendevreview | Rocky proposed openstack/nova master: Add workaround to skip cross-cell service version check https://review.opendev.org/c/openstack/nova/+/1000442 | 12:02 |
| *** LarsErik1 is now known as LarsErikP | 12:18 | |
| opendevreview | Kubilay Kaptanoglu proposed openstack/nova master: Fix simple-tenant-usage state schema for deleted instances https://review.opendev.org/c/openstack/nova/+/1000415 | 13:02 |
| opendevreview | Daniel Marques Caires proposed openstack/nova master: nova: cast set_host_enabled on disable https://review.opendev.org/c/openstack/nova/+/998464 | 13:42 |
| dansmith | gmaan: hmm, I'm not sure I understand, but let me apply that on top while I let the caffeine soak in and see if it helps | 13:43 |
| dansmith | gmaan: nova-compute still exits immediately | 13:46 |
| opendevreview | Anton Iacobaeus proposed openstack/nova master: doc: Add documentation for Intel TDX https://review.opendev.org/c/openstack/nova/+/1000081 | 14:11 |
| opendevreview | Anton Iacobaeus proposed openstack/nova master: libvirt: reject_mem_enc_instances https://review.opendev.org/c/openstack/nova/+/1000082 | 14:11 |
| opendevreview | Anton Iacobaeus proposed openstack/nova master: libvirt: Add os_firmware_secure https://review.opendev.org/c/openstack/nova/+/1000472 | 14:11 |
| gmaan | dansmith: ohk, what is graceful_shutdown_timeout value | 14:58 |
| dansmith | gmaan: 180 | 15:38 |
| dansmith | I gotta run soon, back later | 15:39 |
| gmaan | then it should work. and i hope manager_shutdown_timeout is not set so default 160 applies | 15:57 |
| gmaan | dansmith: just to make sure, 'nova-compute still exits immediately' you mean instance stay active right and stop instance is being interrupted by shutdown immediately and instance did not go to shutoff state | 16:02 |
| bryanfraschetti | Hi folks, I hope you're doing well. Would someone be able to take a look at this patch series https://review.opendev.org/q/topic:%22improve_attachment_resiliance_against_timeout%22? It prevents situations where cinder and nova become out of sync due to volume attachment timeouts (launchpad.net/bugs/2141355) and adds a nova-manage command that could be used to remedy such situations | 16:24 |
| opendevreview | sean mooney proposed openstack/nova master: libvirt: Support Cyborg PCI ARQ managed mode https://review.opendev.org/c/openstack/nova/+/994579 | 18:33 |
| opendevreview | sean mooney proposed openstack/nova master: doc: Add guide for NVIDIA vGPU with SR-IOV variant drivers https://review.opendev.org/c/openstack/nova/+/994160 | 18:33 |
| opendevreview | Daniel Marques Caires proposed openstack/nova master: nova: cast set_host_enabled on disable https://review.opendev.org/c/openstack/nova/+/998464 | 18:37 |
| opendevreview | Daniel Marques Caires proposed openstack/nova master: Add functional regression test for bug #2156927 https://review.opendev.org/c/openstack/nova/+/1000548 | 18:38 |
| opendevreview | Ghanshyam Maan proposed openstack/nova master: Unify the thread poool executors into a central factory https://review.opendev.org/c/openstack/nova/+/998571 | 19:37 |
| dansmith | gmaan: correct.. | 20:08 |
| gmaan | dansmith: other thing to check is systemd timeout TimeoutStopSec, i think that is set as 300 sec in devstack but if that is less than that will stop service immediately | 20:11 |
| dansmith | gmaan: I'm doing a manual kill, not using systemd | 20:12 |
| gmaan | not sure why its not working, I tried with manual kill also and it works fine for me | 20:25 |
| gmaan | can you please paste the log when stop is started and ended | 20:26 |
| dansmith | gmaan: yeah, I'll do some debug myself, I've just had a bunch of other things going on here | 20:28 |
| gmaan | k | 20:29 |
| dansmith | gmaan: hmm, I dunno what was going on but my devstack VM OOMed and I had to restart it ... after that it all seems to be running properly | 21:50 |
| dansmith | I dunno, must have been something not picking up the code changes I was making or something | 21:50 |
| dansmith | however, while I was in graceful shutdown, I sent a stop command for a second instance and it looks like it was received/ignored by nova-compute which AFAIK means it won't be left on the rabbit queue | 21:51 |
| dansmith | when I restarted, it indeed didn't seem to pick up the queued stop request | 21:51 |
| dansmith | I was hoping we'd be able to close the connection so that rabbit would hold inbound requests like that for playback after the shutdown and restart but it appears not.. what is the expectation/ | 21:51 |
| dansmith | ? | 21:51 |
| cardoe | Any chance https://review.opendev.org/c/openstack/nova/+/989002 can land? | 21:55 |
| gmaan | dansmith: yes, it should have stayed in rabbit Q and picked up if compute is coming up again | 22:18 |
| gmaan | compute main rpc server is stopped so it should not have picked by compute | 22:19 |
| gmaan | let me try | 22:19 |
| gmaan | dansmith: humm it worked for me. did you send 2nd stop immediately after service stop? I am wondering if rpcserver stop was racing with that | 22:24 |
| gmaan | i stop instance1 then stopped service, waited for few sec and then stop on instance2. shutdown waited for instance1 stop to complete and then instance1 was in shutoff state and instance2 as active | 22:31 |
| gmaan | when i started the service again (after 60 sec as i added sleep of 35 sec in stop_instance so want to make sure 2nd stop is not picked by compute), instance2 went to shutoff state | 22:32 |
| dansmith | gmaan: but the message from nova-compute that it received and is ignoring it means that we received it (i.e. dequeued from rabbit, no?) | 22:41 |
| gmaan | dansmith: yes, once received it is gone from rabiit q | 22:42 |
| gmaan | but if 2nd stop was received by compute then it should have completed as we do wait on main RPC server so that already picked up things will be completed before shutdiown | 22:43 |
| dansmith | Received method (60, 30) during closing channel 1. This method will be ignored | 22:43 |
| dansmith | right^ ? | 22:43 |
| gmaan | ignored but whom? compute | 22:44 |
| dansmith | that's in the n-cpu log.. my point is, the fact that it's being even noticed by n-cpu means the message is being dequeued from rabbit right? | 22:45 |
| gmaan | yes, it should be dequeued | 22:45 |
| dansmith | I'm confused | 22:46 |
| dansmith | After I started the shutdown and manager is waiting for tasks to complete (the first stop) I issued the second stop.. looks like to me after the first task is completed and we go to do the actual shutdown is when the above message is logged, right before we actually terminate | 22:47 |
| dansmith | gmaan: https://paste.opendev.org/show/boU5DwvAGi3WLacQcn1r/ | 22:47 |
| dansmith | those first few lines show the end of waiting for the first stop, second stop was already sent at that point | 22:48 |
| dansmith | then actual shutdown starts "graceful shutdown finished", then "Received method during closing channel" and then stopping RPC server, then again for some reason | 22:49 |
| dansmith | but those were like a minute or two after I sent the second stop | 22:49 |
| gmaan | can you paste a few more log above that. whn shutdown started | 22:49 |
| gmaan | because that time we do stop main rpcserver where 2nd stop_instance should not be picked | 22:49 |
| dansmith | it waited for minutes, so nore than a few lines but.. | 22:50 |
| dansmith | https://paste.opendev.org/show/bGlDyiz2mraL9dQ3DSfd/ | 22:50 |
| dansmith | first line is graceful start, then waiting for 1 in-progress, somewhere in there is when I issued the second stop | 22:51 |
| dansmith | then L72 is when the first stop finishes its artificial sleep delay and actually completes | 22:51 |
| gmaan | so L5 is where we stop rpc server and i cannot see where is 2ns stop_instance is receveid | 22:53 |
| dansmith | right (on L5).. isn't this us receiving something on the should-be-closed channel? > Received method (60, 30) during closing chan | 22:54 |
| dansmith | nel 1. This method will be ignored | 22:54 |
| dansmith | after restart I don't see my logs that stop gets called again, which is why I'm assuming it is ^ | 22:57 |
| dansmith | one of my instances is wedged because I was testing the manila share stuff before this.. perhaps I'll try getting a fully clean environment and try to reproduce this in case I've got something stuck that is getting in the way | 22:57 |
| gmaan | need to check on oslo.messaging side what is this exactly because in rpcserver.stop() listener stopped listening anything from queue | 22:58 |
| dansmith | ack, that was my expectation of course | 22:58 |
| dansmith | either way, that aside, it's cool to see the graceful shutdown waiting for the stop task as expected now | 22:58 |
| gmaan | it worked for me but yeah please try on clean env. let me check those warning in my cpu log again. i did not gave attension to those as 2nd stop was picked up and successful after compute came up | 22:59 |
| gmaan | dansmith: i can see those amqp warnings even my scenario is passing means 2nd stop was picked up once compute is started again | 23:06 |
| gmaan | i will check these warnings if those are from loopingcall; or so | 23:07 |
| gmaan | later, need to pick kids from school | 23:07 |
Generated by irclog2html.py 4.1.0 by Marius Gedminas - find it at https://mg.pov.lt/irclog2html/!