Skip to content

Commit 407a3f8

Browse files
haitaohuanghaitaohuang
committed
MigTD CVMEmu: use structured logging
- Match the logging pattern used in handle_pre_mig for consistency Signed-off-by: Haitao Huang <haitaohuang@microsoft.com>
1 parent 8e76f58 commit 407a3f8

File tree

1 file changed

+53
-42
lines changed

1 file changed

+53
-42
lines changed

‎src/migtd/src/bin/migtd/cvmemu.rs‎

Lines changed: 53 additions & 42 deletions
Original file line numberDiff line numberDiff line change
@@ -13,12 +13,14 @@ use std::process;
1313
use alloc::vec::Vec;
1414
use migtd;
1515
use migtd::migration::event;
16-
use migtd::migration::logging::{create_logarea, enable_logarea, init_vmm_logger};
16+
use migtd::migration::logging::{
17+
create_logarea, enable_logarea, init_vmm_logger, u8_to_levelfilter,
18+
};
1719
use migtd::migration::session::{exchange_msk, report_status};
1820
use migtd::migration::{MigrationResult, MigtdMigrationInformation};
1921

2022
use tdx_tdcall_emu::tdreport_emu::tdcall_report_emulated;
21-
use tdx_tdcall_emu::tdx_emu::{set_emulated_get_report_data, set_emulated_start_migration};
23+
use tdx_tdcall_emu::tdx_emu::set_emulated_start_migration;
2224
use tdx_tdcall_emu::{init_tcp_emulation_with_mode, start_tcp_server_sync, TcpEmulationMode};
2325

2426
// Import shared functions from main.rs
@@ -416,7 +418,7 @@ fn handle_pre_mig_emu() -> i32 {
416418

417419
match response {
418420
WaitForRequestResponse::EnableLogArea(wfr_info) => {
419-
log::info!("Processing EnableLogArea request\n");
421+
log::info!(migration_request_id = wfr_info.mig_request_id; "Processing EnableLogArea request\n");
420422
let mut data = Vec::new();
421423
let status = enable_logarea(
422424
wfr_info.log_max_level,
@@ -427,30 +429,42 @@ fn handle_pre_mig_emu() -> i32 {
427429
.map(|_| MigrationResult::Success)
428430
.unwrap_or_else(|e| e);
429431

432+
log::info!(migration_request_id = wfr_info.mig_request_id;
433+
"Setting log level to {}\n",
434+
wfr_info.log_max_level
435+
);
436+
log::set_max_level(u8_to_levelfilter(wfr_info.log_max_level));
437+
430438
if status == MigrationResult::Success {
431-
log::info!("Successfully completed Enable LogArea\n");
439+
log::trace!(migration_request_id = wfr_info.mig_request_id; "Successfully completed Enable LogArea\n");
432440
} else {
433-
log::error!(
441+
log::error!(migration_request_id = wfr_info.mig_request_id;
434442
"Failure during Enable LogArea, status code: {:x}\n",
435443
status as u8
436444
);
437445
}
438446

439447
let _ =
440-
report_status(status as u8, wfr_info.mig_request_id, &data).await;
441-
log::info!("ReportStatus for Enable LogArea completed\n");
448+
report_status(status as u8, wfr_info.mig_request_id, &data).await
449+
.map_err(|e| {
450+
log::error!(migration_request_id = wfr_info.mig_request_id;
451+
"Failed to report status for Enable LogArea {:?}\n",
452+
e
453+
);
454+
});
455+
log::trace!(migration_request_id = wfr_info.mig_request_id; "ReportStatus for Enable LogArea completed\n");
442456
// Continue to process next request
443457
}
444458
WaitForRequestResponse::StartMigration(req) => {
445-
log::info!("Processing StartMigration request\n");
459+
log::info!(migration_request_id = req.mig_info.mig_request_id; "Processing StartMigration request\n");
446460
let mut data = Vec::new();
447461

448462
// Call exchange_msk() and log its immediate outcome
449463
let res = exchange_msk(&req, &mut data).await;
450464
match &res {
451-
Ok(_) => log::info!("exchange_msk() returned Ok\n"),
465+
Ok(_) => log::info!(migration_request_id = req.mig_info.mig_request_id; "exchange_msk() returned Ok\n"),
452466
Err(e) => {
453-
log::error!("exchange_msk() returned error code {}\n", *e as u8)
467+
log::error!(migration_request_id = req.mig_info.mig_request_id; "exchange_msk() returned error code {}\n", *e as u8)
454468
}
455469
}
456470
let status =
@@ -459,47 +473,54 @@ fn handle_pre_mig_emu() -> i32 {
459473
// Derive a numeric code without moving `status`
460474
let status_code_u8 = status as u8;
461475

476+
if status_code_u8 == MigrationResult::Success as u8 {
477+
log::trace!(migration_request_id = req.mig_info.mig_request_id; "Successfully completed key exchange\n");
478+
} else {
479+
log::error!(migration_request_id = req.mig_info.mig_request_id; "Failure during key exchange status code: {:x}\n", status_code_u8);
480+
}
481+
462482
// Report status back via vmcall-raw emulation
463483
let empty_data = Vec::new();
464-
if let Err(e) = report_status(
484+
let _ = report_status(
465485
status_code_u8,
466486
req.mig_info.mig_request_id,
467487
&empty_data,
468488
)
469489
.await
470-
{
471-
log::error!("report_status failed with code {}\n", e as u8);
472-
} else {
473-
log::info!("report_status completed successfully\n");
474-
}
490+
.map_err(|e| {
491+
log::error!(migration_request_id = req.mig_info.mig_request_id;
492+
"Failed to report status {:?}\n",
493+
e
494+
);
495+
});
496+
log::trace!(migration_request_id = req.mig_info.mig_request_id; "ReportStatus for key exchange completed\n");
475497

476498
if status_code_u8 == MigrationResult::Success as u8 {
477-
log::info!("Migration key exchange successful!\n");
499+
log::info!(migration_request_id = req.mig_info.mig_request_id; "Migration key exchange successful!\n");
478500
return 0;
479501
} else {
480502
let status_code = status_code_u8 as i32;
481-
log::error!(
503+
log::error!(migration_request_id = req.mig_info.mig_request_id;
482504
"Migration key exchange failed with code: {}\n",
483505
status_code
484506
);
485507
return status_code;
486508
}
487509
}
488510
WaitForRequestResponse::GetTdReport(report_info) => {
489-
log::info!("Processing GetReportData request\n");
490-
log::info!(" Request ID: {}\n", report_info.mig_request_id);
491-
log::info!(
492-
" ReportData (first 32 bytes): {:02x?}\n",
511+
log::info!(migration_request_id = report_info.mig_request_id; "Processing GetReportData request\n");
512+
log::debug!(migration_request_id = report_info.mig_request_id;
513+
"ReportData (first 32 bytes): {:02x?}\n",
493514
&report_info.reportdata[0..32]
494515
);
495516

496517
// Generate TD report using the reportdata
497-
log::info!("Generating TD report with vTPM interface\n");
518+
log::debug!(migration_request_id = report_info.mig_request_id; "Generating TD report with vTPM interface\n");
498519

499520
let (status_code_u8, report_data) =
500521
match tdcall_report_emulated(&report_info.reportdata) {
501522
Ok(td_report) => {
502-
log::info!("TD report generated successfully\n");
523+
log::debug!(migration_request_id = report_info.mig_request_id; "TD report generated successfully\n");
503524

504525
// Convert the TD report to bytes
505526
let report_bytes = unsafe {
@@ -509,42 +530,32 @@ fn handle_pre_mig_emu() -> i32 {
509530
)
510531
};
511532

512-
log::info!(
533+
log::debug!(migration_request_id = report_info.mig_request_id;
513534
"TD report size: {} bytes\n",
514535
report_bytes.len()
515536
);
516-
log::info!(
517-
"TD report (first 32 bytes): {:02x?}\n",
518-
&report_bytes[0..32]
519-
);
520537

521538
// Return success with the TD report as data
522539
(MigrationResult::Success as u8, report_bytes.to_vec())
523540
}
524541
Err(e) => {
525-
log::error!("Failed to generate TD report: {:?}\n", e);
542+
log::error!(migration_request_id = report_info.mig_request_id; "Failed to generate TD report: {:?}\n", e);
526543
(MigrationResult::TdxModuleError as u8, Vec::new())
527544
}
528545
};
529546

530-
if let Err(e) = report_status(
547+
let _ = report_status(
531548
status_code_u8,
532549
report_info.mig_request_id,
533550
&report_data,
534551
)
535-
.await
536-
{
537-
log::error!("report_status failed with code {}\n", e as u8);
552+
.await;
553+
if status_code_u8 == MigrationResult::Success as u8 {
554+
log::trace!(migration_request_id = report_info.mig_request_id; "Successfully completed get TDREPORT\n");
538555
} else {
539-
if status_code_u8 == MigrationResult::Success as u8 {
540-
log::info!("GetReportData request completed successfully\n");
541-
} else {
542-
log::error!(
543-
"GetReportData request failed with status {}\n",
544-
status_code_u8
545-
);
546-
}
556+
log::error!(migration_request_id = report_info.mig_request_id; "Failure during get TDREPORT status code: {:x}\n", status_code_u8);
547557
}
558+
log::trace!(migration_request_id = report_info.mig_request_id; "ReportStatus for get TDREPORT completed.\n");
548559
// Continue to process next request (migration)
549560
}
550561
}

0 commit comments

Comments
 (0)