1 // Copyright © 2022 Intel Corporation 2 // 3 // SPDX-License-Identifier: Apache-2.0 4 // 5 6 // Performance tests 7 8 use crate::{mean, PerformanceTestControl}; 9 use std::fs; 10 use std::path::PathBuf; 11 use std::thread; 12 use std::time::Duration; 13 use test_infra::Error as InfraError; 14 use test_infra::*; 15 16 #[cfg(target_arch = "x86_64")] 17 pub const FOCAL_IMAGE_NAME: &str = "focal-server-cloudimg-amd64-custom-20210609-0.raw"; 18 #[cfg(target_arch = "aarch64")] 19 pub const FOCAL_IMAGE_NAME: &str = "focal-server-cloudimg-arm64-custom-20210929-0-update-tool.raw"; 20 21 #[allow(dead_code)] 22 #[derive(Debug)] 23 enum Error { 24 BootTimeParse, 25 Infra(InfraError), 26 } 27 28 impl From<InfraError> for Error { 29 fn from(e: InfraError) -> Self { 30 Self::Infra(e) 31 } 32 } 33 34 const BLK_IO_TEST_IMG: &str = "/var/tmp/ch-blk-io-test.img"; 35 36 pub fn init_tests() { 37 // The test image can not be created on tmpfs (e.g. /tmp) filesystem, 38 // as tmpfs does not support O_DIRECT 39 assert!(exec_host_command_output(&format!( 40 "dd if=/dev/zero of={BLK_IO_TEST_IMG} bs=1M count=4096" 41 )) 42 .status 43 .success()); 44 } 45 46 pub fn cleanup_tests() { 47 fs::remove_file(BLK_IO_TEST_IMG) 48 .unwrap_or_else(|_| panic!("Failed to remove file '{BLK_IO_TEST_IMG}'.")); 49 } 50 51 // Performance tests are expected to be executed sequentially, so we can 52 // start VM guests with the same IP while putting them on a different 53 // private network. The default constructor "Guest::new()" does not work 54 // well, as we can easily create more than 256 VMs from repeating various 55 // performance tests dozens times in a single run. 56 fn performance_test_new_guest(disk_config: Box<dyn DiskConfig>) -> Guest { 57 Guest::new_from_ip_range(disk_config, "172.19", 0) 58 } 59 60 const DIRECT_KERNEL_BOOT_CMDLINE: &str = 61 "root=/dev/vda1 console=hvc0 rw systemd.journald.forward_to_console=1"; 62 63 // Creates the path for direct kernel boot and return the path. 64 // For x86_64, this function returns the vmlinux kernel path. 65 // For AArch64, this function returns the PE kernel path. 66 fn direct_kernel_boot_path() -> PathBuf { 67 let mut workload_path = dirs::home_dir().unwrap(); 68 workload_path.push("workloads"); 69 70 let mut kernel_path = workload_path; 71 #[cfg(target_arch = "x86_64")] 72 kernel_path.push("vmlinux"); 73 #[cfg(target_arch = "aarch64")] 74 kernel_path.push("Image"); 75 76 kernel_path 77 } 78 79 pub fn performance_net_throughput(control: &PerformanceTestControl) -> f64 { 80 let test_timeout = control.test_timeout; 81 let (rx, bandwidth) = control.net_control.unwrap(); 82 83 let focal = UbuntuDiskConfig::new(FOCAL_IMAGE_NAME.to_string()); 84 let guest = performance_test_new_guest(Box::new(focal)); 85 86 let num_queues = control.num_queues.unwrap(); 87 let queue_size = control.queue_size.unwrap(); 88 let net_params = format!( 89 "tap=,mac={},ip={},mask=255.255.255.0,num_queues={},queue_size={}", 90 guest.network.guest_mac, guest.network.host_ip, num_queues, queue_size, 91 ); 92 93 let mut child = GuestCommand::new(&guest) 94 .args(["--cpus", &format!("boot={num_queues}")]) 95 .args(["--memory", "size=4G"]) 96 .args(["--kernel", direct_kernel_boot_path().to_str().unwrap()]) 97 .args(["--cmdline", DIRECT_KERNEL_BOOT_CMDLINE]) 98 .default_disks() 99 .args(["--net", net_params.as_str()]) 100 .capture_output() 101 .verbosity(VerbosityLevel::Warn) 102 .set_print_cmd(false) 103 .spawn() 104 .unwrap(); 105 106 let r = std::panic::catch_unwind(|| { 107 guest.wait_vm_boot(None).unwrap(); 108 measure_virtio_net_throughput(test_timeout, num_queues / 2, &guest, rx, bandwidth).unwrap() 109 }); 110 111 let _ = child.kill(); 112 let output = child.wait_with_output().unwrap(); 113 114 match r { 115 Ok(r) => r, 116 Err(e) => { 117 handle_child_output(Err(e), &output); 118 panic!("test failed!"); 119 } 120 } 121 } 122 123 pub fn performance_net_latency(control: &PerformanceTestControl) -> f64 { 124 let focal = UbuntuDiskConfig::new(FOCAL_IMAGE_NAME.to_string()); 125 let guest = performance_test_new_guest(Box::new(focal)); 126 127 let num_queues = control.num_queues.unwrap(); 128 let queue_size = control.queue_size.unwrap(); 129 let net_params = format!( 130 "tap=,mac={},ip={},mask=255.255.255.0,num_queues={},queue_size={}", 131 guest.network.guest_mac, guest.network.host_ip, num_queues, queue_size, 132 ); 133 134 let mut child = GuestCommand::new(&guest) 135 .args(["--cpus", &format!("boot={num_queues}")]) 136 .args(["--memory", "size=4G"]) 137 .args(["--kernel", direct_kernel_boot_path().to_str().unwrap()]) 138 .args(["--cmdline", DIRECT_KERNEL_BOOT_CMDLINE]) 139 .default_disks() 140 .args(["--net", net_params.as_str()]) 141 .capture_output() 142 .verbosity(VerbosityLevel::Warn) 143 .set_print_cmd(false) 144 .spawn() 145 .unwrap(); 146 147 let r = std::panic::catch_unwind(|| { 148 guest.wait_vm_boot(None).unwrap(); 149 150 // 'ethr' tool will measure the latency multiple times with provided test time 151 let latency = measure_virtio_net_latency(&guest, control.test_timeout).unwrap(); 152 mean(&latency).unwrap() 153 }); 154 155 let _ = child.kill(); 156 let output = child.wait_with_output().unwrap(); 157 158 match r { 159 Ok(r) => r, 160 Err(e) => { 161 handle_child_output(Err(e), &output); 162 panic!("test failed!"); 163 } 164 } 165 } 166 167 fn parse_boot_time_output(output: &[u8]) -> Result<f64, Error> { 168 std::panic::catch_unwind(|| { 169 let l: Vec<String> = String::from_utf8_lossy(output) 170 .lines() 171 .filter(|l| l.contains("Debug I/O port: Kernel code")) 172 .map(|l| l.to_string()) 173 .collect(); 174 175 assert_eq!( 176 l.len(), 177 2, 178 "Expecting two matching lines for 'Debug I/O port: Kernel code'" 179 ); 180 181 let time_stamp_kernel_start = { 182 let s = l[0].split("--").collect::<Vec<&str>>(); 183 assert_eq!( 184 s.len(), 185 2, 186 "Expecting '--' for the matching line of 'Debug I/O port' output" 187 ); 188 189 // Sample output: "[Debug I/O port: Kernel code 0x40] 0.096537 seconds" 190 assert!( 191 s[1].contains("0x40"), 192 "Expecting kernel code '0x40' for 'linux_kernel_start' time stamp output" 193 ); 194 let t = s[1].split_whitespace().collect::<Vec<&str>>(); 195 assert_eq!( 196 t.len(), 197 8, 198 "Expecting exact '8' words from the 'Debug I/O port' output" 199 ); 200 assert!( 201 t[7].eq("seconds"), 202 "Expecting 'seconds' as the the last word of the 'Debug I/O port' output" 203 ); 204 205 t[6].parse::<f64>().unwrap() 206 }; 207 208 let time_stamp_user_start = { 209 let s = l[1].split("--").collect::<Vec<&str>>(); 210 assert_eq!( 211 s.len(), 212 2, 213 "Expecting '--' for the matching line of 'Debug I/O port' output" 214 ); 215 216 // Sample output: "Debug I/O port: Kernel code 0x41] 0.198980 seconds" 217 assert!( 218 s[1].contains("0x41"), 219 "Expecting kernel code '0x41' for 'linux_kernel_start' time stamp output" 220 ); 221 let t = s[1].split_whitespace().collect::<Vec<&str>>(); 222 assert_eq!( 223 t.len(), 224 8, 225 "Expecting exact '8' words from the 'Debug I/O port' output" 226 ); 227 assert!( 228 t[7].eq("seconds"), 229 "Expecting 'seconds' as the the last word of the 'Debug I/O port' output" 230 ); 231 232 t[6].parse::<f64>().unwrap() 233 }; 234 235 time_stamp_user_start - time_stamp_kernel_start 236 }) 237 .map_err(|_| { 238 eprintln!( 239 "=============== boot-time output ===============\n\n{}\n\n===========end============\n\n", 240 String::from_utf8_lossy(output) 241 ); 242 Error::BootTimeParse 243 }) 244 } 245 246 fn measure_boot_time(cmd: &mut GuestCommand, test_timeout: u32) -> Result<f64, Error> { 247 let mut child = cmd 248 .capture_output() 249 .verbosity(VerbosityLevel::Warn) 250 .set_print_cmd(false) 251 .spawn() 252 .unwrap(); 253 254 thread::sleep(Duration::new(test_timeout as u64, 0)); 255 let _ = child.kill(); 256 let output = child.wait_with_output().unwrap(); 257 258 parse_boot_time_output(&output.stderr).map_err(|e| { 259 eprintln!( 260 "\n\n==== Start child stdout ====\n\n{}\n\n==== End child stdout ====", 261 String::from_utf8_lossy(&output.stdout) 262 ); 263 eprintln!( 264 "\n\n==== Start child stderr ====\n\n{}\n\n==== End child stderr ====", 265 String::from_utf8_lossy(&output.stderr) 266 ); 267 268 e 269 }) 270 } 271 272 pub fn performance_boot_time(control: &PerformanceTestControl) -> f64 { 273 let r = std::panic::catch_unwind(|| { 274 let focal = UbuntuDiskConfig::new(FOCAL_IMAGE_NAME.to_string()); 275 let guest = performance_test_new_guest(Box::new(focal)); 276 let mut cmd = GuestCommand::new(&guest); 277 278 let c = cmd 279 .args([ 280 "--cpus", 281 &format!("boot={}", control.num_boot_vcpus.unwrap_or(1)), 282 ]) 283 .args(["--memory", "size=1G"]) 284 .args(["--kernel", direct_kernel_boot_path().to_str().unwrap()]) 285 .args(["--cmdline", DIRECT_KERNEL_BOOT_CMDLINE]) 286 .args(["--console", "off"]) 287 .default_disks(); 288 289 measure_boot_time(c, control.test_timeout).unwrap() 290 }); 291 292 match r { 293 Ok(r) => r, 294 Err(_) => { 295 panic!("test failed!"); 296 } 297 } 298 } 299 300 pub fn performance_boot_time_pmem(control: &PerformanceTestControl) -> f64 { 301 let r = std::panic::catch_unwind(|| { 302 let focal = UbuntuDiskConfig::new(FOCAL_IMAGE_NAME.to_string()); 303 let guest = performance_test_new_guest(Box::new(focal)); 304 let mut cmd = GuestCommand::new(&guest); 305 let c = cmd 306 .args([ 307 "--cpus", 308 &format!("boot={}", control.num_boot_vcpus.unwrap_or(1)), 309 ]) 310 .args(["--memory", "size=1G,hugepages=on"]) 311 .args(["--kernel", direct_kernel_boot_path().to_str().unwrap()]) 312 .args(["--cmdline", "root=/dev/pmem0p1 console=ttyS0 quiet rw"]) 313 .args(["--console", "off"]) 314 .args([ 315 "--pmem", 316 format!( 317 "file={}", 318 guest.disk_config.disk(DiskType::OperatingSystem).unwrap() 319 ) 320 .as_str(), 321 ]); 322 323 measure_boot_time(c, control.test_timeout).unwrap() 324 }); 325 326 match r { 327 Ok(r) => r, 328 Err(_) => { 329 panic!("test failed!"); 330 } 331 } 332 } 333 334 pub fn performance_block_io(control: &PerformanceTestControl) -> f64 { 335 let test_timeout = control.test_timeout; 336 let num_queues = control.num_queues.unwrap(); 337 let (fio_ops, bandwidth) = control.fio_control.as_ref().unwrap(); 338 339 let focal = UbuntuDiskConfig::new(FOCAL_IMAGE_NAME.to_string()); 340 let guest = performance_test_new_guest(Box::new(focal)); 341 let api_socket = guest 342 .tmp_dir 343 .as_path() 344 .join("cloud-hypervisor.sock") 345 .to_str() 346 .unwrap() 347 .to_string(); 348 349 let mut child = GuestCommand::new(&guest) 350 .args(["--cpus", &format!("boot={num_queues}")]) 351 .args(["--memory", "size=4G"]) 352 .args(["--kernel", direct_kernel_boot_path().to_str().unwrap()]) 353 .args(["--cmdline", DIRECT_KERNEL_BOOT_CMDLINE]) 354 .args([ 355 "--disk", 356 format!( 357 "path={}", 358 guest.disk_config.disk(DiskType::OperatingSystem).unwrap() 359 ) 360 .as_str(), 361 format!( 362 "path={}", 363 guest.disk_config.disk(DiskType::CloudInit).unwrap() 364 ) 365 .as_str(), 366 format!("path={BLK_IO_TEST_IMG}").as_str(), 367 ]) 368 .default_net() 369 .args(["--api-socket", &api_socket]) 370 .capture_output() 371 .verbosity(VerbosityLevel::Warn) 372 .set_print_cmd(false) 373 .spawn() 374 .unwrap(); 375 376 let r = std::panic::catch_unwind(|| { 377 guest.wait_vm_boot(None).unwrap(); 378 379 let fio_command = format!( 380 "sudo fio --filename=/dev/vdc --name=test --output-format=json \ 381 --direct=1 --bs=4k --ioengine=io_uring --iodepth=64 \ 382 --rw={fio_ops} --runtime={test_timeout} --numjobs={num_queues}" 383 ); 384 let output = guest 385 .ssh_command(&fio_command) 386 .map_err(InfraError::SshCommand) 387 .unwrap(); 388 389 // Parse fio output 390 if *bandwidth { 391 parse_fio_output(&output, fio_ops, num_queues).unwrap() 392 } else { 393 parse_fio_output_iops(&output, fio_ops, num_queues).unwrap() 394 } 395 }); 396 397 let _ = child.kill(); 398 let output = child.wait_with_output().unwrap(); 399 400 match r { 401 Ok(r) => r, 402 Err(e) => { 403 handle_child_output(Err(e), &output); 404 panic!("test failed!"); 405 } 406 } 407 } 408 409 #[cfg(test)] 410 mod tests { 411 use super::*; 412 413 #[test] 414 fn test_parse_iperf3_output() { 415 let output = r#" 416 { 417 "end": { 418 "sum_sent": { 419 "start": 0, 420 "end": 5.000196, 421 "seconds": 5.000196, 422 "bytes": 14973836248, 423 "bits_per_second": 23957198874.604115, 424 "retransmits": 0, 425 "sender": false 426 } 427 } 428 } 429 "#; 430 assert_eq!( 431 parse_iperf3_output(output.as_bytes(), true, true).unwrap(), 432 23957198874.604115 433 ); 434 435 let output = r#" 436 { 437 "end": { 438 "sum_received": { 439 "start": 0, 440 "end": 5.000626, 441 "seconds": 5.000626, 442 "bytes": 24703557800, 443 "bits_per_second": 39520744482.79, 444 "sender": true 445 } 446 } 447 } 448 "#; 449 assert_eq!( 450 parse_iperf3_output(output.as_bytes(), false, true).unwrap(), 451 39520744482.79 452 ); 453 let output = r#" 454 { 455 "end": { 456 "sum": { 457 "start": 0, 458 "end": 5.000036, 459 "seconds": 5.000036, 460 "bytes": 29944971264, 461 "bits_per_second": 47911877363.396217, 462 "jitter_ms": 0.0038609822983198556, 463 "lost_packets": 16, 464 "packets": 913848, 465 "lost_percent": 0.0017508382137948542, 466 "sender": true 467 } 468 } 469 } 470 "#; 471 assert_eq!( 472 parse_iperf3_output(output.as_bytes(), true, false).unwrap(), 473 182765.08409139456 474 ); 475 } 476 477 #[test] 478 fn test_parse_ethr_latency_output() { 479 let output = r#"{"Time":"2022-02-08T03:52:50Z","Title":"","Type":"INFO","Message":"Using destination: 192.168.249.2, ip: 192.168.249.2, port: 8888"} 480 {"Time":"2022-02-08T03:52:51Z","Title":"","Type":"INFO","Message":"Running latency test: 1000, 1"} 481 {"Time":"2022-02-08T03:52:51Z","Title":"","Type":"LatencyResult","RemoteAddr":"192.168.249.2","Protocol":"TCP","Avg":"80.712us","Min":"61.677us","P50":"257.014us","P90":"74.418us","P95":"107.283us","P99":"119.309us","P999":"142.100us","P9999":"216.341us","Max":"216.341us"} 482 {"Time":"2022-02-08T03:52:52Z","Title":"","Type":"LatencyResult","RemoteAddr":"192.168.249.2","Protocol":"TCP","Avg":"79.826us","Min":"55.129us","P50":"598.996us","P90":"73.849us","P95":"106.552us","P99":"122.152us","P999":"142.459us","P9999":"474.280us","Max":"474.280us"} 483 {"Time":"2022-02-08T03:52:53Z","Title":"","Type":"LatencyResult","RemoteAddr":"192.168.249.2","Protocol":"TCP","Avg":"78.239us","Min":"56.999us","P50":"396.820us","P90":"69.469us","P95":"115.421us","P99":"119.404us","P999":"130.158us","P9999":"258.686us","Max":"258.686us"}"#; 484 485 let ret = parse_ethr_latency_output(output.as_bytes()).unwrap(); 486 let reference = vec![80.712_f64, 79.826_f64, 78.239_f64]; 487 assert_eq!(ret, reference); 488 } 489 490 #[test] 491 fn test_parse_boot_time_output() { 492 let output = r#" 493 cloud-hypervisor: 161.167103ms: <vcpu0> INFO:vmm/src/vm.rs:392 -- [Debug I/O port: Kernel code 0x40] 0.132 seconds 494 cloud-hypervisor: 613.57361ms: <vcpu0> INFO:vmm/src/vm.rs:392 -- [Debug I/O port: Kernel code 0x41] 0.5845 seconds 495 "#; 496 497 assert_eq!(parse_boot_time_output(output.as_bytes()).unwrap(), 0.4525); 498 } 499 500 #[test] 501 fn test_parse_fio_output() { 502 let output = r#" 503 { 504 "jobs" : [ 505 { 506 "read" : { 507 "io_bytes" : 1965273088, 508 "io_kbytes" : 1919212, 509 "bw_bytes" : 392976022, 510 "bw" : 383765, 511 "iops" : 95941.411718, 512 "runtime" : 5001, 513 "total_ios" : 479803, 514 "short_ios" : 0, 515 "drop_ios" : 0 516 } 517 } 518 ] 519 } 520 "#; 521 522 let bps = 1965273088_f64 / (5001_f64 / 1000_f64); 523 assert_eq!( 524 parse_fio_output(output, &FioOps::RandomRead, 1).unwrap(), 525 bps 526 ); 527 assert_eq!(parse_fio_output(output, &FioOps::Read, 1).unwrap(), bps); 528 529 let output = r#" 530 { 531 "jobs" : [ 532 { 533 "write" : { 534 "io_bytes" : 1172783104, 535 "io_kbytes" : 1145296, 536 "bw_bytes" : 234462835, 537 "bw" : 228967, 538 "iops" : 57241.903239, 539 "runtime" : 5002, 540 "total_ios" : 286324, 541 "short_ios" : 0, 542 "drop_ios" : 0 543 } 544 }, 545 { 546 "write" : { 547 "io_bytes" : 1172234240, 548 "io_kbytes" : 1144760, 549 "bw_bytes" : 234353106, 550 "bw" : 228860, 551 "iops" : 57215.113954, 552 "runtime" : 5002, 553 "total_ios" : 286190, 554 "short_ios" : 0, 555 "drop_ios" : 0 556 } 557 } 558 ] 559 } 560 "#; 561 562 let bps = 1172783104_f64 / (5002_f64 / 1000_f64) + 1172234240_f64 / (5002_f64 / 1000_f64); 563 assert_eq!( 564 parse_fio_output(output, &FioOps::RandomWrite, 2).unwrap(), 565 bps 566 ); 567 assert_eq!(parse_fio_output(output, &FioOps::Write, 2).unwrap(), bps); 568 } 569 } 570