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 HvLite 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 { message_mode: true },
67            ..Default::default()
68        }
69    }
70
71    fn inspect(&mut self, req: inspect::Request<'_>, task: Option<&mut GelChannel>) {
72        let _ = (req, task);
73    }
74
75    fn open(
76        &mut self,
77        channel: RawAsyncChannel<GpadlRingMem>,
78        _guest_memory: guestmem::GuestMemory,
79    ) -> Result<Self::Runner, ChannelOpenError> {
80        let pipe = MessagePipe::new(channel)?;
81        Ok(GelChannel::new(pipe))
82    }
83
84    async fn run(
85        &mut self,
86        stop: &mut StopTask<'_>,
87        channel: &mut GelChannel,
88    ) -> Result<(), task_control::Cancelled> {
89        stop.until_stopped(async {
90            if let Err(err) = channel.process(self).await {
91                tracing::error!(
92                    error = &err as &dyn std::error::Error,
93                    "trace channel failed"
94                );
95            }
96        })
97        .await
98    }
99
100    fn supports_save_restore(
101        &mut self,
102    ) -> Option<
103        &mut dyn SaveRestoreSimpleVmbusDevice<SavedState = Self::SavedState, Runner = Self::Runner>,
104    > {
105        Some(self)
106    }
107}
108
109impl SaveRestoreSimpleVmbusDevice for GuestEmulationLog {
110    fn save_open(&mut self, _runner: &Self::Runner) -> Self::SavedState {
111        NoSavedState
112    }
113
114    fn restore_open(
115        &mut self,
116        NoSavedState: Self::SavedState,
117        channel: RawAsyncChannel<GpadlRingMem>,
118    ) -> Result<Self::Runner, ChannelOpenError> {
119        let pipe = MessagePipe::new(channel)?;
120        Ok(GelChannel::new(pipe))
121    }
122}
123
124#[derive(Deserialize, Debug, Default)]
125struct TraceFields<'a> {
126    #[serde(borrow)]
127    message: Option<Cow<'a, str>>,
128    #[serde(flatten, borrow)]
129    extra: ExtraFields<'a>,
130}
131
132#[derive(Deserialize, Debug, Default)]
133#[serde(transparent)]
134struct ExtraFields<'a> {
135    #[serde(borrow)]
136    map: HashMap<Cow<'a, str>, serde_json::value::Value>,
137}
138
139impl std::fmt::Display for ExtraFields<'_> {
140    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
141        let mut map = f.debug_map();
142        for (k, v) in &self.map {
143            map.entry(k, &format_args!("{}", v));
144        }
145        map.finish()
146    }
147}
148
149#[derive(Deserialize, Debug)]
150struct TraceData<'a> {
151    #[serde(borrow)]
152    target: Cow<'a, str>,
153    #[serde(borrow)]
154    level: Cow<'a, str>,
155    #[serde(default, borrow)]
156    fields: TraceFields<'a>,
157    #[serde(flatten, borrow)]
158    extra: ExtraFields<'a>,
159}
160
161/// The GEL task.
162pub struct GelChannel<T: RingMem = GpadlRingMem> {
163    channel: MessagePipe<T>,
164}
165
166impl<T: RingMem + Unpin> GelChannel<T> {
167    fn new(channel: MessagePipe<T>) -> Self {
168        Self { channel }
169    }
170
171    async fn process(&mut self, _state: &mut GuestEmulationLog) -> Result<(), Error> {
172        let mut buffer = vec![0; get_protocol::TRACE_LOGGING_NOTIFICATION_MAX_SIZE];
173        loop {
174            let n = self
175                .channel
176                .recv(buffer.as_mut_bytes())
177                .await
178                .map_err(Error::PipeFailure)?;
179
180            if n == 0 {
181                break;
182            }
183
184            let buffer = &buffer[..n];
185
186            let (header, buffer) =
187                get_protocol::TraceLoggingNotificationHeader::read_from_prefix(buffer)
188                    .map_err(|_| Error::InvalidPayloadSize(n))?; // TODO: zerocopy: map_err (https://github.com/microsoft/openvmm/issues/759)
189
190            let message = buffer
191                .get(
192                    header.message.offset as usize
193                        ..(header.message.offset + header.message.size) as usize,
194                )
195                .ok_or(Error::InvalidTraceSize(n as u16))?;
196
197            match serde_json::from_slice::<'_, TraceData<'_>>(message) {
198                Ok(data) => match &*data.level {
199                    "ERROR" => {
200                        tracing::error!(
201                            target: "paravisor_log",
202                            inner_target = &*data.target,
203                            message = data.fields.message.as_deref(),
204                            fields = %data.fields.extra,
205                            extra = %data.extra,
206                        )
207                    }
208                    "WARN" => {
209                        tracing::warn!(
210                            target: "paravisor_log",
211                            inner_target = &*data.target,
212                            message = data.fields.message.as_deref(),
213                            fields = %data.fields.extra,
214                            extra = %data.extra,
215                        )
216                    }
217                    "INFO" => {
218                        tracing::info!(
219                            target: "paravisor_log",
220                            inner_target = &*data.target,
221                            message = data.fields.message.as_deref(),
222                            fields = %data.fields.extra,
223                            extra = %data.extra,
224                        )
225                    }
226                    "DEBUG" => {
227                        tracing::debug!(
228                            target: "paravisor_log",
229                            inner_target = &*data.target,
230                            message = data.fields.message.as_deref(),
231                            fields = %data.fields.extra,
232                            extra = %data.extra,
233                        )
234                    }
235                    "TRACE" => {
236                        tracing::trace!(
237                            target: "paravisor_log",
238                            inner_target = &*data.target,
239                            message = data.fields.message.as_deref(),
240                            fields = %data.fields.extra,
241                            extra = %data.extra,
242                        )
243                    }
244                    some_level => {
245                        tracing::info!(
246                            target: "paravisor_log",
247                            inner_level = some_level,
248                            inner_target = &*data.target,
249                            message = data.fields.message.as_deref(),
250                            fields = %data.fields.extra,
251                            extra = %data.extra,
252                        )
253                    }
254                },
255                Err(err) => {
256                    tracing::warn!(
257                        target: "paravisor_log",
258                        inner_level = ?header.level,
259                        error = &err as &dyn std::error::Error,
260                        message = String::from_utf8_lossy(message).as_ref(),
261                        "failed to parse trace",
262                    )
263                }
264            }
265        }
266        Ok(())
267    }
268}