Skip to main content

guest_emulation_log/
lib.rs

1// Copyright (c) Microsoft Corporation.
2// Licensed under the MIT License.
3
4//! Guest Emulation Log - GEL
5//!
6//! The GEL is the host side of a communication channel that uses VMBUS to
7//! send logs from the guest to the host. This is an implementation to support
8//! better integration testing within the OpenVMM CI.
9
10#![expect(missing_docs)]
11#![forbid(unsafe_code)]
12
13pub mod resolver;
14
15use async_trait::async_trait;
16use serde::Deserialize;
17use std::borrow::Cow;
18use std::collections::HashMap;
19use task_control::StopTask;
20use thiserror::Error;
21use vmbus_async::async_dgram::AsyncRecvExt;
22use vmbus_async::pipe::MessagePipe;
23use vmbus_channel::RawAsyncChannel;
24use vmbus_channel::bus::ChannelType;
25use vmbus_channel::bus::OfferParams;
26use vmbus_channel::channel::ChannelOpenError;
27use vmbus_channel::gpadl_ring::GpadlRingMem;
28use vmbus_channel::simple::SaveRestoreSimpleVmbusDevice;
29use vmbus_channel::simple::SimpleVmbusDevice;
30use vmbus_ring::RingMem;
31use vmcore::save_restore::NoSavedState;
32use zerocopy::FromBytes;
33use zerocopy::IntoBytes;
34
35#[derive(Debug, Error)]
36enum Error {
37    #[error("pipe failed")]
38    PipeFailure(#[source] std::io::Error),
39    #[error("trace message has invalid size {0}")]
40    InvalidTraceSize(u16),
41    #[error("invalid payload length {0}")]
42    InvalidPayloadSize(usize),
43}
44
45/// VMBUS device that implements the host side of the Guest Emulation Log protocol.
46#[non_exhaustive]
47pub struct GuestEmulationLog {}
48
49impl GuestEmulationLog {
50    /// Create a new Host side GEL device.
51    pub fn new() -> Self {
52        Self {}
53    }
54}
55
56#[async_trait]
57impl SimpleVmbusDevice for GuestEmulationLog {
58    type Runner = GelChannel;
59    type SavedState = NoSavedState;
60
61    fn offer(&self) -> OfferParams {
62        OfferParams {
63            interface_name: "gel".to_owned(),
64            interface_id: get_protocol::GUEST_EMULATION_INTERFACE_TYPE,
65            instance_id: get_protocol::GET_LOG_INTERFACE_GUID,
66            channel_type: ChannelType::Pipe {
67                message_mode: true,
68                user_defined: Default::default(),
69                pipe_flags: Default::default(),
70            },
71            ..Default::default()
72        }
73    }
74
75    fn inspect(&mut self, req: inspect::Request<'_>, task: Option<&mut GelChannel>) {
76        let _ = (req, task);
77    }
78
79    fn open(
80        &mut self,
81        channel: RawAsyncChannel<GpadlRingMem>,
82        _guest_memory: guestmem::GuestMemory,
83    ) -> Result<Self::Runner, ChannelOpenError> {
84        let pipe = MessagePipe::new(channel)?;
85        Ok(GelChannel::new(pipe))
86    }
87
88    async fn run(
89        &mut self,
90        stop: &mut StopTask<'_>,
91        channel: &mut GelChannel,
92    ) -> Result<(), task_control::Cancelled> {
93        stop.until_stopped(async {
94            if let Err(err) = channel.process(self).await {
95                tracing::error!(
96                    error = &err as &dyn std::error::Error,
97                    "trace channel failed"
98                );
99            }
100        })
101        .await
102    }
103
104    fn supports_save_restore(
105        &mut self,
106    ) -> Option<
107        &mut dyn SaveRestoreSimpleVmbusDevice<SavedState = Self::SavedState, Runner = Self::Runner>,
108    > {
109        Some(self)
110    }
111}
112
113impl SaveRestoreSimpleVmbusDevice for GuestEmulationLog {
114    fn save_open(&mut self, _runner: &Self::Runner) -> Self::SavedState {
115        NoSavedState
116    }
117
118    fn restore_open(
119        &mut self,
120        NoSavedState: Self::SavedState,
121        channel: RawAsyncChannel<GpadlRingMem>,
122    ) -> Result<Self::Runner, ChannelOpenError> {
123        let pipe = MessagePipe::new(channel)?;
124        Ok(GelChannel::new(pipe))
125    }
126}
127
128#[derive(Deserialize, Debug, Default)]
129struct TraceFields<'a> {
130    #[serde(borrow)]
131    message: Option<Cow<'a, str>>,
132    #[serde(flatten, borrow)]
133    extra: ExtraFields<'a>,
134}
135
136#[derive(Deserialize, Debug, Default)]
137#[serde(transparent)]
138struct ExtraFields<'a> {
139    #[serde(borrow)]
140    map: HashMap<Cow<'a, str>, serde_json::value::Value>,
141}
142
143impl std::fmt::Display for ExtraFields<'_> {
144    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
145        let mut map = f.debug_map();
146        for (k, v) in &self.map {
147            map.entry(k, &format_args!("{}", v));
148        }
149        map.finish()
150    }
151}
152
153#[derive(Deserialize, Debug)]
154struct TraceData<'a> {
155    #[serde(borrow)]
156    target: Cow<'a, str>,
157    #[serde(borrow)]
158    level: Cow<'a, str>,
159    #[serde(default, borrow)]
160    fields: TraceFields<'a>,
161    #[serde(flatten, borrow)]
162    extra: ExtraFields<'a>,
163}
164
165/// The GEL task.
166pub struct GelChannel<T: RingMem = GpadlRingMem> {
167    channel: MessagePipe<T>,
168}
169
170impl<T: RingMem + Unpin> GelChannel<T> {
171    fn new(channel: MessagePipe<T>) -> Self {
172        Self { channel }
173    }
174
175    async fn process(&mut self, _state: &mut GuestEmulationLog) -> Result<(), Error> {
176        let mut buffer = vec![0; get_protocol::TRACE_LOGGING_NOTIFICATION_MAX_SIZE];
177        loop {
178            let n = self
179                .channel
180                .recv(buffer.as_mut_bytes())
181                .await
182                .map_err(Error::PipeFailure)?;
183
184            if n == 0 {
185                break;
186            }
187
188            let buffer = &buffer[..n];
189
190            let (header, buffer) =
191                get_protocol::TraceLoggingNotificationHeader::read_from_prefix(buffer)
192                    .map_err(|_| Error::InvalidPayloadSize(n))?; // TODO: zerocopy: map_err (https://github.com/microsoft/openvmm/issues/759)
193
194            let message = buffer
195                .get(
196                    header.message.offset as usize
197                        ..(header.message.offset + header.message.size) as usize,
198                )
199                .ok_or(Error::InvalidTraceSize(n as u16))?;
200
201            match serde_json::from_slice::<'_, TraceData<'_>>(message) {
202                Ok(data) => match &*data.level {
203                    "ERROR" => {
204                        tracing::error!(
205                            target: "paravisor_log",
206                            inner_target = &*data.target,
207                            message = data.fields.message.as_deref(),
208                            fields = %data.fields.extra,
209                            extra = %data.extra,
210                        )
211                    }
212                    "WARN" => {
213                        tracing::warn!(
214                            target: "paravisor_log",
215                            inner_target = &*data.target,
216                            message = data.fields.message.as_deref(),
217                            fields = %data.fields.extra,
218                            extra = %data.extra,
219                        )
220                    }
221                    "INFO" => {
222                        tracing::info!(
223                            target: "paravisor_log",
224                            inner_target = &*data.target,
225                            message = data.fields.message.as_deref(),
226                            fields = %data.fields.extra,
227                            extra = %data.extra,
228                        )
229                    }
230                    "DEBUG" => {
231                        tracing::debug!(
232                            target: "paravisor_log",
233                            inner_target = &*data.target,
234                            message = data.fields.message.as_deref(),
235                            fields = %data.fields.extra,
236                            extra = %data.extra,
237                        )
238                    }
239                    "TRACE" => {
240                        tracing::trace!(
241                            target: "paravisor_log",
242                            inner_target = &*data.target,
243                            message = data.fields.message.as_deref(),
244                            fields = %data.fields.extra,
245                            extra = %data.extra,
246                        )
247                    }
248                    some_level => {
249                        tracing::info!(
250                            target: "paravisor_log",
251                            inner_level = some_level,
252                            inner_target = &*data.target,
253                            message = data.fields.message.as_deref(),
254                            fields = %data.fields.extra,
255                            extra = %data.extra,
256                        )
257                    }
258                },
259                Err(err) => {
260                    tracing::warn!(
261                        target: "paravisor_log",
262                        inner_level = ?header.level,
263                        error = &err as &dyn std::error::Error,
264                        message = String::from_utf8_lossy(message).as_ref(),
265                        "failed to parse trace",
266                    )
267                }
268            }
269        }
270        Ok(())
271    }
272}