Skip to content

Commit 0c24377

Browse files
author
Jonathan Woollett-Light
committed
feat: Add instrumentation profiler
Adds `tracing_flame` as code instrumentation based profiler that can be used to profile Firecracker. Signed-off-by: Jonathan Woollett-Light <jcawl@amazon.co.uk>
1 parent 2031800 commit 0c24377

File tree

9 files changed

+93
-36
lines changed

9 files changed

+93
-36
lines changed

‎Cargo.lock

Lines changed: 12 additions & 0 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎src/api_server/src/request/logger.rs

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -43,6 +43,7 @@ mod tests {
4343
show_level: Some(false),
4444
show_log_origin: Some(false),
4545
filter: None,
46+
profile_path: None,
4647
};
4748
match vmm_action_from_request(parse_put_logger(&Body::new(body)).unwrap()) {
4849
VmmAction::ConfigureLogger(cfg) => assert_eq!(cfg, expected_cfg),
@@ -62,6 +63,7 @@ mod tests {
6263
show_level: Some(false),
6364
show_log_origin: Some(false),
6465
filter: None,
66+
profile_path: None,
6567
};
6668
match vmm_action_from_request(parse_put_logger(&Body::new(body)).unwrap()) {
6769
VmmAction::ConfigureLogger(cfg) => assert_eq!(cfg, expected_cfg),

‎src/cpu-template-helper/src/main.rs

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -117,7 +117,7 @@ fn run(cli: Cli) -> Result<(), HelperError> {
117117
Command::Template(op) => match op {
118118
TemplateOperation::Dump { config, output } => {
119119
let config = read_to_string(config)?;
120-
let (vmm, _) = utils::build_microvm_from_config(&config)?;
120+
let ((vmm, _), _flame_guard) = utils::build_microvm_from_config(&config)?;
121121

122122
let cpu_config = template::dump::dump(vmm)?;
123123

@@ -142,7 +142,8 @@ fn run(cli: Cli) -> Result<(), HelperError> {
142142
}
143143
TemplateOperation::Verify { config } => {
144144
let config = read_to_string(config)?;
145-
let (vmm, vm_resources) = utils::build_microvm_from_config(&config)?;
145+
let ((vmm, vm_resources), _flame_guard) =
146+
utils::build_microvm_from_config(&config)?;
146147

147148
let cpu_template = vm_resources
148149
.vm_config
@@ -157,7 +158,7 @@ fn run(cli: Cli) -> Result<(), HelperError> {
157158
Command::Fingerprint(op) => match op {
158159
FingerprintOperation::Dump { config, output } => {
159160
let config = read_to_string(config)?;
160-
let (vmm, _) = utils::build_microvm_from_config(&config)?;
161+
let ((vmm, _), _flame_guard) = utils::build_microvm_from_config(&config)?;
161162

162163
let fingerprint = fingerprint::dump::dump(vmm)?;
163164

‎src/cpu-template-helper/src/template/dump/mod.rs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -47,7 +47,7 @@ mod tests {
4747
let tmp_file = TempFile::new().unwrap();
4848
let valid_config =
4949
generate_config(&kernel_image_path, tmp_file.as_path().to_str().unwrap());
50-
let (vmm, _) = build_microvm_from_config(&valid_config).unwrap();
50+
let ((vmm, _), _flame_guard) = build_microvm_from_config(&valid_config).unwrap();
5151

5252
assert!(dump(vmm).is_ok());
5353
}

‎src/cpu-template-helper/src/utils/mod.rs

Lines changed: 12 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -69,19 +69,27 @@ pub enum UtilsError {
6969
BuildMicroVm(#[from] StartMicrovmError),
7070
}
7171

72+
#[allow(clippy::type_complexity)]
7273
#[tracing::instrument(level = "trace", skip(config))]
7374
pub fn build_microvm_from_config(
7475
config: &str,
75-
) -> Result<(Arc<Mutex<Vmm>>, VmResources), UtilsError> {
76+
) -> Result<
77+
(
78+
(Arc<Mutex<Vmm>>, VmResources),
79+
Option<vmm::vmm_config::logger::FlameGuard>,
80+
),
81+
UtilsError,
82+
> {
7683
// Prepare resources from the given config file.
7784
let instance_info = InstanceInfo {
7885
id: "anonymous-instance".to_string(),
7986
state: VmState::NotStarted,
8087
vmm_version: CPU_TEMPLATE_HELPER_VERSION.to_string(),
8188
app_name: "cpu-template-helper".to_string(),
8289
};
83-
let vm_resources = VmResources::from_json(config, &instance_info, HTTP_MAX_PAYLOAD_SIZE, None)
84-
.map_err(UtilsError::CreateVmResources)?;
90+
let (vm_resources, flame_guard) =
91+
VmResources::from_json(config, &instance_info, HTTP_MAX_PAYLOAD_SIZE, None)
92+
.map_err(UtilsError::CreateVmResources)?;
8593
let mut event_manager = EventManager::new().unwrap();
8694
let seccomp_filters = get_empty_filters();
8795

@@ -93,7 +101,7 @@ pub fn build_microvm_from_config(
93101
&seccomp_filters,
94102
)?;
95103

96-
Ok((vmm, vm_resources))
104+
Ok(((vmm, vm_resources), flame_guard))
97105
}
98106

99107
#[tracing::instrument(level = "trace", skip(path, suffix))]

‎src/firecracker/src/main.rs

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -301,7 +301,7 @@ fn main_exec() -> Result<(), MainError> {
301301
};
302302

303303
// Configure logger, the logger handles can be used to re-configure the logger with the API.
304-
let logger_handles = {
304+
let (logger_handles, _flame_guard) = {
305305
let level_res = arguments
306306
.single_value("level")
307307
.map(|s| LevelFilter::from_str(s))
@@ -319,6 +319,7 @@ fn main_exec() -> Result<(), MainError> {
319319
show_level: Some(arguments.flag_present("show-level")),
320320
show_log_origin: Some(arguments.flag_present("show-log-origin")),
321321
filter,
322+
profile_path: None,
322323
};
323324
logger_config
324325
.init()
@@ -541,7 +542,7 @@ fn build_microvm_from_json(
541542
mmds_size_limit: usize,
542543
metadata_json: Option<&str>,
543544
) -> Result<(VmResources, Arc<Mutex<vmm::Vmm>>), BuildFromJsonError> {
544-
let mut vm_resources =
545+
let (mut vm_resources, _flame_guard) =
545546
VmResources::from_json(&config_json, &instance_info, mmds_size_limit, metadata_json)
546547
.map_err(BuildFromJsonError::ParseFromJson)?;
547548
vm_resources.boot_timer = boot_timer_enabled;
@@ -617,7 +618,7 @@ fn run_without_api(
617618
.expect("Failed to start the event manager");
618619

619620
if let Some(exit_code) = vmm.lock().unwrap().shutdown_exit_code() {
620-
return Err(RunWithoutApiError::Shutdown(exit_code));
621+
break Err(RunWithoutApiError::Shutdown(exit_code));
621622
}
622623
}
623624
}

‎src/vmm/Cargo.toml

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@ vm-fdt = "0.2.0"
3131
vm-superio = "0.7.0"
3232
tracing = { version = "0.1.37", features = ["max_level_debug"] }
3333
tracing-subscriber = "0.3.17"
34+
tracing-flame = "0.2.0"
3435
log = { version = "0.4.17", features = ["serde"] }
3536

3637
dumbo = { path = "../dumbo" }

‎src/vmm/src/resources.rs

Lines changed: 14 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -138,12 +138,15 @@ impl VmResources {
138138
instance_info: &InstanceInfo,
139139
mmds_size_limit: usize,
140140
metadata_json: Option<&str>,
141-
) -> Result<Self, ResourcesError> {
141+
) -> Result<(Self, Option<crate::vmm_config::logger::FlameGuard>), ResourcesError> {
142142
let vmm_config = serde_json::from_str::<VmmConfig>(config_json)?;
143143

144-
if let Some(logger) = vmm_config.logger {
145-
logger.init()?;
146-
}
144+
let flame_guard = if let Some(logger) = vmm_config.logger {
145+
let (_logger_handles, flame_guard) = logger.init()?;
146+
flame_guard
147+
} else {
148+
None
149+
};
147150

148151
if let Some(metrics) = vmm_config.metrics {
149152
init_metrics(metrics)?;
@@ -199,7 +202,7 @@ impl VmResources {
199202
resources.build_entropy_device(entropy_device_config)?;
200203
}
201204

202-
Ok(resources)
205+
Ok((resources, flame_guard))
203206
}
204207

205208
#[tracing::instrument(level = "trace", skip(self))]
@@ -1058,7 +1061,7 @@ mod tests {
10581061
kernel_file.as_path().to_str().unwrap(),
10591062
rootfs_file.as_path().to_str().unwrap(),
10601063
);
1061-
let resources = VmResources::from_json(
1064+
let (resources, _flame_guard) = VmResources::from_json(
10621065
json.as_str(),
10631066
&default_instance_info,
10641067
1200,
@@ -1146,7 +1149,7 @@ mod tests {
11461149
rootfs_file.as_path().to_str().unwrap(),
11471150
);
11481151

1149-
let vm_resources = VmResources::from_json(
1152+
let (vm_resources, _flame_guard) = VmResources::from_json(
11501153
json.as_str(),
11511154
&default_instance_info,
11521155
HTTP_MAX_PAYLOAD_SIZE,
@@ -1206,7 +1209,7 @@ mod tests {
12061209
);
12071210

12081211
{
1209-
let resources = VmResources::from_json(
1212+
let (resources, _flame_guard) = VmResources::from_json(
12101213
json.as_str(),
12111214
&InstanceInfo::default(),
12121215
HTTP_MAX_PAYLOAD_SIZE,
@@ -1221,7 +1224,7 @@ mod tests {
12211224

12221225
{
12231226
// In this case the mmds data store will be initialised but the config still None.
1224-
let resources = VmResources::from_json(
1227+
let (resources, _flame_guard) = VmResources::from_json(
12251228
json.as_str(),
12261229
&InstanceInfo::default(),
12271230
HTTP_MAX_PAYLOAD_SIZE,
@@ -1281,7 +1284,7 @@ mod tests {
12811284
kernel_file.as_path().to_str().unwrap(),
12821285
rootfs_file.as_path().to_str().unwrap(),
12831286
);
1284-
let resources = VmResources::from_json(
1287+
let (resources, _flame_guard) = VmResources::from_json(
12851288
json.as_str(),
12861289
&InstanceInfo::default(),
12871290
HTTP_MAX_PAYLOAD_SIZE,
@@ -1340,7 +1343,7 @@ mod tests {
13401343
kernel_file.as_path().to_str().unwrap(),
13411344
rootfs_file.as_path().to_str().unwrap(),
13421345
);
1343-
let resources = VmResources::from_json(
1346+
let (resources, _flame_guard) = VmResources::from_json(
13441347
json.as_str(),
13451348
&InstanceInfo::default(),
13461349
HTTP_MAX_PAYLOAD_SIZE,

‎src/vmm/src/vmm_config/logger.rs

Lines changed: 43 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -3,8 +3,10 @@
33

44
use std::convert::From;
55
use std::fmt;
6-
use std::io::LineWriter;
6+
use std::fs::OpenOptions;
7+
use std::io::{BufWriter, LineWriter};
78
use std::os::unix::fs::OpenOptionsExt;
9+
use std::path::PathBuf;
810
use std::str::FromStr;
911
use std::sync::atomic::AtomicBool;
1012
use std::sync::atomic::Ordering::SeqCst;
@@ -107,7 +109,7 @@ impl FromStr for LevelFilter {
107109
#[serde(deny_unknown_fields)]
108110
pub struct LoggerConfig {
109111
/// Named pipe or file used as output for logs.
110-
pub log_path: Option<std::path::PathBuf>,
112+
pub log_path: Option<PathBuf>,
111113
// TODO Deprecate this API argument.
112114
/// The level of the Logger.
113115
pub level: Option<LevelFilter>,
@@ -117,6 +119,8 @@ pub struct LoggerConfig {
117119
pub show_log_origin: Option<bool>,
118120
/// Filter components. If this is `Some` it overrides `self.level`.
119121
pub filter: Option<FilterArgs>,
122+
/// Named pipe or file used as output for profile.
123+
pub profile_path: Option<PathBuf>,
120124
}
121125

122126
/// Error type for [`LoggerConfig::init`].
@@ -186,17 +190,24 @@ type FmtHandle<F, G> = tracing_subscriber::reload::Handle<
186190
>,
187191
>;
188192

193+
/// An alias for the specific [`tracing_flame::FlushGuard`] used to flush the
194+
/// [`tracing_flame::FlameLayer`].
195+
pub type FlameGuard = tracing_flame::FlushGuard<BufWriter<std::fs::File>>;
196+
189197
impl LoggerConfig {
190198
/// Initializes the logger.
191199
///
192200
/// Returns handles that can be used to dynamically re-configure the logger.
193201
pub fn init(
194202
self,
195203
) -> Result<
196-
LoggerHandles<
197-
impl Fn(&tracing::Metadata<'_>) -> bool,
198-
impl Fn(&tracing::Metadata<'_>) -> bool,
199-
>,
204+
(
205+
LoggerHandles<
206+
impl Fn(&tracing::Metadata<'_>) -> bool,
207+
impl Fn(&tracing::Metadata<'_>) -> bool,
208+
>,
209+
Option<FlameGuard>,
210+
),
200211
InitLoggerError,
201212
> {
202213
// Update default filter to match passed arguments.
@@ -243,7 +254,7 @@ impl LoggerConfig {
243254
// consuming the message that is flushed to the two pipes, we are opening it
244255
// with `O_NONBLOCK` flag. In this case, writing to a pipe will start failing
245256
// when reaching 64K of unconsumed content.
246-
let file = std::fs::OpenOptions::new()
257+
let file = OpenOptions::new()
247258
.custom_flags(libc::O_NONBLOCK)
248259
.read(true)
249260
.write(true)
@@ -264,19 +275,37 @@ impl LoggerConfig {
264275
ReloadLayer::new(fmt_subscriber)
265276
};
266277

267-
Registry::default()
268-
.with(filter)
269-
.with(fmt)
270-
.try_init()
271-
.map_err(InitLoggerError::Init)?;
278+
// Setup flame layer
279+
let flame_guard = if let Some(profile_path) = self.profile_path {
280+
let writer = OpenOptions::new().write(true).open(profile_path).unwrap();
281+
let buffer = BufWriter::new(writer);
282+
let flame_layer = tracing_flame::FlameLayer::new(buffer);
283+
let guard = flame_layer.flush_on_drop();
284+
285+
Registry::default()
286+
.with(filter)
287+
.with(fmt)
288+
.with(flame_layer)
289+
.try_init()
290+
.map_err(InitLoggerError::Init)?;
291+
292+
Some(guard)
293+
} else {
294+
Registry::default()
295+
.with(filter)
296+
.with(fmt)
297+
.try_init()
298+
.map_err(InitLoggerError::Init)?;
299+
None
300+
};
272301

273302
tracing::error!("Error level logs enabled.");
274303
tracing::warn!("Warn level logs enabled.");
275304
tracing::info!("Info level logs enabled.");
276305
tracing::debug!("Debug level logs enabled.");
277306
tracing::trace!("Trace level logs enabled.");
278307

279-
Ok(LoggerHandles { fmt: fmt_handle })
308+
Ok((LoggerHandles { fmt: fmt_handle }, flame_guard))
280309
}
281310
/// Updates the logger using the given handles.
282311
pub fn update(
@@ -292,7 +321,7 @@ impl LoggerConfig {
292321
// message that is flushed to the two pipes, we are opening it with `O_NONBLOCK` flag.
293322
// In this case, writing to a pipe will start failing when reaching 64K of unconsumed
294323
// content.
295-
let file = std::fs::OpenOptions::new()
324+
let file = OpenOptions::new()
296325
.custom_flags(libc::O_NONBLOCK)
297326
.read(true)
298327
.write(true)

0 commit comments

Comments
 (0)