Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

event_monitor: refactor the implementation to support concurrent access #5633

Merged

Conversation

brkp
Copy link
Contributor

@brkp brkp commented Jul 29, 2023

This patch modifies event_monitor to ensure that concurrent access to event_log from multiple threads is safe. Previously, the event_log function would acquire a reference to the event log file and write to it without doing any synchronization, which made it prone to data races. This issue likely went under the radar because the relevant SAFETY comment on the unsafe block was incomplete.

The new implementation spawns a dedicated thread named event-monitor solely for writing to the file. It uses the MPMC channel exposed by flume to pass messages to the event-monitor thread. Since flume::Sender<T> implements Sync, it is safe for multiple threads to share it and send messages to the event-monitor thread.

I looked into doing this with the unbounded MPSC in the standard library but unfortunately, it's !Sync, which actually is considered to be an API mistake. Meaning, the following snippet has soundness issues and is not safe if tx were to be a std::sync::mpsc::Sender<T>:

[...]
    if let Some(monitor_handle) = unsafe { MONITOR.as_ref() } {
        [...]
        if let Ok(event) = serde_json::to_string_pretty(&event) {|
            // invocation of this snippet from multiple threads
            // in the case `tx` is `!Sync` is not safe
            monitor_handle.tx.send(event).ok();
        }
    }
[...]

If anyone is aware of a workaround/better pattern for implementing this with the MPSC in the standard library, I'd love to hear about it.

Here are some links that can provide more context for this PR:

@brkp brkp requested a review from a team as a code owner July 29, 2023 23:02
@brkp brkp force-pushed the event-monitor-thread-safety branch from 22be4e3 to 992aae7 Compare July 29, 2023 23:06
Copy link
Member

@likebreath likebreath left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The current implementation looks good to me. I wonder how does the the "event-monitor" thread exit gracefully? Also, looks like this thread won't terminate together with other thread upon exit_evt.

@rbradford
Copy link
Member

The current implementation looks good to me. I wonder how does the the "event-monitor" thread exit gracefully? Also, looks like this thread won't terminate together with other thread upon exit_evt.

exit_evt is used for VM specific threads - this thread is a VMM thread and like e.g. the http/dbus API threads it will be exited when the VMM process terminates. Unless it needs to do some specific cleanup (FDs will be automatically closed by the OS) then there is no need to do any special handling.

rbradford
rbradford previously approved these changes Jul 31, 2023
event_monitor/src/lib.rs Outdated Show resolved Hide resolved
@likebreath
Copy link
Member

The current implementation looks good to me. I wonder how does the the "event-monitor" thread exit gracefully? Also, looks like this thread won't terminate together with other thread upon exit_evt.

exit_evt is used for VM specific threads - this thread is a VMM thread and like e.g. the http/dbus API threads it will be exited when the VMM process terminates. Unless it needs to do some specific cleanup (FDs will be automatically closed by the OS) then there is no need to do any special handling.

Thanks for the explanation, Rob.

likebreath
likebreath previously approved these changes Jul 31, 2023
@brkp
Copy link
Contributor Author

brkp commented Aug 1, 2023

Do you think that we should write to exit_evt when the event-monitor thread panics? This is the behavior implemented by other VMM threads as well, e.g. HTTP/D-Bus API threads. @likebreath @rbradford

@rbradford
Copy link
Member

The current implementation looks good to me. I wonder how does the the "event-monitor" thread exit gracefully? Also, looks like this thread won't terminate together with other thread upon exit_evt.

exit_evt is used for VM specific threads - this thread is a VMM thread and like e.g. the http/dbus API threads it will be exited when the VMM process terminates. Unless it needs to do some specific cleanup (FDs will be automatically closed by the OS) then there is no need to do any special handling.

Thanks for the explanation, Rob.

Thanks to @brkp's point my reply was slightly off. There is an exit_evt in Vmm and it is used by support threads in the VMM (like the HTTP API server) but only to signal they have panicked/prematurely exited; they don't listen for the event and react to it like the VM support threads.

@rbradford
Copy link
Member

Do you think that we should write to exit_evt when the event-monitor thread panics? This is the behavior implemented by other VMM threads as well, e.g. HTTP/D-Bus API threads. @likebreath @rbradford

Yes - please make it consistent with the other VMM support threads. I think there should also be some new seccomp rules too?

@rbradford rbradford marked this pull request as draft August 3, 2023 14:59
@rbradford
Copy link
Member

@brkp I've drafted this as I think there are still some more bits to do...?

@brkp
Copy link
Contributor Author

brkp commented Aug 3, 2023

@brkp I've drafted this as I think there are still some more bits to do...?

Thanks -- yeah, sorry I haven't had the time to continue working on this. I also want to improve the error handling in here, alongside the previously mentioned things (seccomp rules, making the thread behavior more consistent with the rest of the VMM threads, etc.).

This patch modifies `event_monitor` to ensure that concurrent access to
`event_log` from multiple threads is safe. Previously, the `event_log`
function would acquire a reference to the event log file and write
to it without doing any synchronization, which made it prone to
data races. This issue likely went under the radar because the
relevant `SAFETY` comment on the unsafe block was incomplete.

The new implementation spawns a dedicated thread named `event-monitor`
solely for writing to the file. It uses the MPMC channel exposed by
`flume` to pass messages to the `event-monitor` thread. Since
`flume::Sender<T>` implements `Sync`, it is safe for multiple threads
to share it and send messages to the `event-monitor` thread.
This is not possible with `std::sync::mpsc::Sender<T>` since it's
`!Sync`, meaning it is not safe for it to be shared between different
threads.

The `event_monitor::set_monitor` function now only initializes
the required global state and returns an instance of the
`Monitor` struct. This decouples the actual logging logic from the
`event_monitor` crate. The `event-monitor` thread is then spawned by
the `vmm` crate.

Signed-off-by: Omer Faruk Bayram <omer.faruk@sartura.hr>
@brkp brkp force-pushed the event-monitor-thread-safety branch from 992aae7 to fea89bd Compare August 6, 2023 19:27
@brkp
Copy link
Contributor Author

brkp commented Aug 6, 2023

I've modified the event_monitor::set_monitor function so that now it only initializes the necessary global state and hands out a Monitor struct instance.

This change separates the logging logic from event_monitor, giving the caller more flexibility. vmm then uses this Monitor struct to spawn a thread called event-monitor and implements its own logging logic, which currently only writes to a file.

@rbradford @likebreath

@brkp brkp marked this pull request as ready for review August 6, 2023 20:53
Copy link
Member

@likebreath likebreath left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Changes look good to me. Just one thing about the seccomp filter. I think it is better to include brk and mmap to avoid potential violations for allocating memory on the event_monitor thread.

@likebreath likebreath dismissed stale reviews from rbradford and themself August 7, 2023 01:07

new changes

@brkp brkp force-pushed the event-monitor-thread-safety branch from fea89bd to 9c647cd Compare August 7, 2023 05:21
@brkp
Copy link
Contributor Author

brkp commented Aug 7, 2023

Thanks for catching that! @likebreath Added brk and mmap to the list of allowed calls as well.

Signed-off-by: Omer Faruk Bayram <omer.faruk@sartura.hr>
@brkp brkp force-pushed the event-monitor-thread-safety branch from 9c647cd to 8d104b2 Compare August 8, 2023 05:46
@rbradford rbradford merged commit a0c8bf4 into cloud-hypervisor:main Aug 9, 2023
22 checks passed
@brkp brkp deleted the event-monitor-thread-safety branch August 9, 2023 18:01
@peng6662001
Copy link
Contributor

peng6662001 commented Sep 21, 2023

@brkp Could you please share a way to verify this patch on aarch64?

@brkp
Copy link
Contributor Author

brkp commented Sep 21, 2023

@peng6662001 Would you mind providing a bit more context? I'm not quite sure what you mean by "verify".

@peng6662001
Copy link
Contributor

@brkp Have you ever encountered a "concurrent access" bug?How to reproduce it?
I use --event-monitor path=/tmp/event.json to start the vm and the file /tmp/event.json looks fine with old version of CloudHypervisor.

@brkp
Copy link
Contributor Author

brkp commented Sep 29, 2023

@peng6662001 Hey, sorry for the late reply.

The previous implementation of event-monitor allows users to call the event_log function, which writes to a log file, from multiple threads without doing any synchronization.

This becomes problematic when two threads race to write to the log file at the same time. While this may not have been a significant issue in the past due to the scarce use of event-monitor throughout the code base, it is still an incorrect implementation going forward.

likebreath added a commit to likebreath/cloud-hypervisor that referenced this pull request Nov 9, 2023
Since the 'write()' to the event file was moved to its own thread
(see cloud-hypervisor#5633), we have no reliable way to read the latest contents of
the event file from our integration tests, since we can't ensure the
'read()' from our test always happen after 'write()' is completed from
Cloud Hypervisor. This is also why we started to see random failures on
snapshot_restore tests (particularly when the system workload is high).

This patch adds a 1s sleep before reading the event file to mitigate the
random failures.

Signed-off-by: Bo Chen <chen.bo@intel.com>
rbradford pushed a commit that referenced this pull request Nov 14, 2023
Since the 'write()' to the event file was moved to its own thread
(see #5633), we have no reliable way to read the latest contents of
the event file from our integration tests, since we can't ensure the
'read()' from our test always happen after 'write()' is completed from
Cloud Hypervisor. This is also why we started to see random failures on
snapshot_restore tests (particularly when the system workload is high).

This patch adds a 1s sleep before reading the event file to mitigate the
random failures.

Signed-off-by: Bo Chen <chen.bo@intel.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Status: Done
Development

Successfully merging this pull request may close these issues.

None yet

4 participants