Adding cancelcontext to closing vmbus channels #734
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
erfrimod
commented
Jan 28, 2025
| actions.copy_to_slots(&mut slots, self.hcl); | ||
| } else { | ||
| actions.run_actions(self.hcl); | ||
| } |
There was a problem hiding this comment.
Added check for None because in testing I was hitting a crash here:
[78.547532] state_unit: INFO servicing_save_vtl2{ correlation_id=b4a14652-340a-4fee-9707-307701aaabf8}:save_units:state_change{ operation="save"}: state change complete duration=32.541219ms
[78.552453] mana_driver::resources: ERROR leaking resources
[78.553500] vmbus_server: INFO revoking channel offer_id=OfferId(0)
[78.553635] vmbus_server::channels: INFO rescinding channel from guest channel_id=0xa
[78.553847] vmbus_server: INFO revoking channel offer_id=OfferId(e)
[78.553945] vmbus_server::channels: INFO rescinding channel from guest channel_id=0xf
[78.554098] vmbus_server: INFO revoking channel offer_id=OfferId(f)
[78.554194] vmbus_server::channels: INFO rescinding channel from guest channel_id=0x10
[78.554349] vmbus_server: INFO revoking channel offer_id=OfferId(10)
[78.554442] vmbus_server::channels: INFO rescinding channel from guest channel_id=0x11
[78.585466] underhill_core::dispatch: ERROR error while handling servicing error=cancelled waiting for vmbus channel close: deadline exceeded
[78.589991] vmbus_relay_intercept_device: INFO matching channel offered offer=OfferInfo { offer: OfferChannel { interface_id: 0e0b6031-5213-4934-818b-38d90ced39db, instance_id: b6650ff7-33bc-4840-8048-e0676786f393, rsvd: [0, 0, 0, 0], flags: OfferFlags { enumerate_device_interface: true, confidential_ring_buffer: false, confidential_external_memory: false, named_pipe_mode: true, tlnpi_provider: false }, mmio_megabytes: 0, user_defined: UserDefinedData([4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]), subchannel_index: 0, mmio_megabytes_optional: 0, channel_id: ChannelId(7), monitor_id: ff, monitor_allocated: 0, is_dedicated: 1, connection_id: 2007 }, request_se
[78.590006] vmbus_relay_intercept_device: nd: SenderCore(ManuallyDrop { value: Queue { remote: OnceLock(<uninit>), local: Mutex { data: LocalQueue { messages: ErasedVecDeque { cap: 280, head: 0, len: 0 }, ports: [], waker: Some(Waker { data: 0x57170180c50, vtable: 0x7fe86c02e1b8 }), remote: false, receiver_gone: false, remove_closed: false, new_handler: 0x7fe86b87d330 } } } }), response_recv: ReceiverCore { queue: ReceiverQueue(Queue { remote: OnceLock(<uninit>), local: Mutex { data: LocalQueue { messages: ErasedVecDeque { cap: 10, head: 4, len: 0 }, ports: [], waker: Some(Waker { data: 0x571700c2bb0, vtable: 0x7fe86c00d5a8 }), remote: false, receiver_gone: false, remove_closed: false, new_handler: 0x7fe86b87d330 } } }), ports: PortHandlerList([]), terminated: false } }
[78.594794] [U] task 'o
[78.594805] [U] called `Option::unwrap()` on a `None` value
There was a problem hiding this comment.
Thanks for finding this. Should be fixed by #739.
erfrimod
commented
Jan 28, 2025
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
shutdown_vf_devices(), the method where nic_shutdown() is called, doesn't have a CancelContext. So the wait for vmbus operations during unload_for_servicing() is unbounded. We have seen shutdown_mana() wait indefinitely.
shutdown_pci_devices() returns a ShutdownError. And something similar could be put in place for shutdown_vf_devices().
Note: There may be a hang in the future if the vmbus stays unresponsive. At best this change allows us to return an error from shutdown_vf_devices() so we know where in shutdown_mana() the delay is coming from.
DONE:
TBD:
Testing with a 1 ms duration fails, but leaves VM in a bad state
The vm sees a lot of disk errors on the vmbus. And
Stop-Vmgets stuck.Output from ohcldiag:
Output from kmsg log:
Output on the VM:
Testing with a 1 second duration succeeds normally
Output from ohcldiag:
Output from kmsg log: