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