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={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 = control.net_rx.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).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 .into_iter() 172 .filter(|l| l.contains("Debug I/O port: Kernel code")) 173 .map(|l| l.to_string()) 174 .collect(); 175 176 assert_eq!( 177 l.len(), 178 2, 179 "Expecting two matching lines for 'Debug I/O port: Kernel code'" 180 ); 181 182 let time_stamp_kernel_start = { 183 let s = l[0].split("--").collect::<Vec<&str>>(); 184 assert_eq!( 185 s.len(), 186 2, 187 "Expecting '--' for the matching line of 'Debug I/O port' output" 188 ); 189 190 // Sample output: "[Debug I/O port: Kernel code 0x40] 0.096537 seconds" 191 assert!( 192 s[1].contains("0x40"), 193 "Expecting kernel code '0x40' for 'linux_kernel_start' time stamp output" 194 ); 195 let t = s[1].split_whitespace().collect::<Vec<&str>>(); 196 assert_eq!( 197 t.len(), 198 8, 199 "Expecting exact '8' words from the 'Debug I/O port' output" 200 ); 201 assert!( 202 t[7].eq("seconds"), 203 "Expecting 'seconds' as the the last word of the 'Debug I/O port' output" 204 ); 205 206 t[6].parse::<f64>().unwrap() 207 }; 208 209 let time_stamp_user_start = { 210 let s = l[1].split("--").collect::<Vec<&str>>(); 211 assert_eq!( 212 s.len(), 213 2, 214 "Expecting '--' for the matching line of 'Debug I/O port' output" 215 ); 216 217 // Sample output: "Debug I/O port: Kernel code 0x41] 0.198980 seconds" 218 assert!( 219 s[1].contains("0x41"), 220 "Expecting kernel code '0x41' for 'linux_kernel_start' time stamp output" 221 ); 222 let t = s[1].split_whitespace().collect::<Vec<&str>>(); 223 assert_eq!( 224 t.len(), 225 8, 226 "Expecting exact '8' words from the 'Debug I/O port' output" 227 ); 228 assert!( 229 t[7].eq("seconds"), 230 "Expecting 'seconds' as the the last word of the 'Debug I/O port' output" 231 ); 232 233 t[6].parse::<f64>().unwrap() 234 }; 235 236 time_stamp_user_start - time_stamp_kernel_start 237 }) 238 .map_err(|_| { 239 eprintln!( 240 "=============== boot-time output ===============\n\n{}\n\n===========end============\n\n", 241 String::from_utf8_lossy(output) 242 ); 243 Error::BootTimeParse 244 }) 245 } 246 247 fn measure_boot_time(cmd: &mut GuestCommand, test_timeout: u32) -> Result<f64, Error> { 248 let mut child = cmd 249 .capture_output() 250 .verbosity(VerbosityLevel::Warn) 251 .set_print_cmd(false) 252 .spawn() 253 .unwrap(); 254 255 thread::sleep(Duration::new(test_timeout as u64, 0)); 256 let _ = child.kill(); 257 let output = child.wait_with_output().unwrap(); 258 259 parse_boot_time_output(&output.stderr).map_err(|e| { 260 eprintln!( 261 "\n\n==== Start child stdout ====\n\n{}\n\n==== End child stdout ====", 262 String::from_utf8_lossy(&output.stdout) 263 ); 264 eprintln!( 265 "\n\n==== Start child stderr ====\n\n{}\n\n==== End child stderr ====", 266 String::from_utf8_lossy(&output.stderr) 267 ); 268 269 e 270 }) 271 } 272 273 pub fn performance_boot_time(control: &PerformanceTestControl) -> f64 { 274 let r = std::panic::catch_unwind(|| { 275 let focal = UbuntuDiskConfig::new(FOCAL_IMAGE_NAME.to_string()); 276 let guest = performance_test_new_guest(Box::new(focal)); 277 let mut cmd = GuestCommand::new(&guest); 278 279 let c = cmd 280 .args([ 281 "--cpus", 282 &format!("boot={}", control.num_boot_vcpus.unwrap_or(1)), 283 ]) 284 .args(["--memory", "size=1G"]) 285 .args(["--kernel", direct_kernel_boot_path().to_str().unwrap()]) 286 .args(["--cmdline", DIRECT_KERNEL_BOOT_CMDLINE]) 287 .args(["--console", "off"]) 288 .default_disks(); 289 290 measure_boot_time(c, control.test_timeout).unwrap() 291 }); 292 293 match r { 294 Ok(r) => r, 295 Err(_) => { 296 panic!("test failed!"); 297 } 298 } 299 } 300 301 pub fn performance_boot_time_pmem(control: &PerformanceTestControl) -> f64 { 302 let r = std::panic::catch_unwind(|| { 303 let focal = UbuntuDiskConfig::new(FOCAL_IMAGE_NAME.to_string()); 304 let guest = performance_test_new_guest(Box::new(focal)); 305 let mut cmd = GuestCommand::new(&guest); 306 let c = cmd 307 .args([ 308 "--cpus", 309 &format!("boot={}", control.num_boot_vcpus.unwrap_or(1)), 310 ]) 311 .args(["--memory", "size=1G,hugepages=on"]) 312 .args(["--kernel", direct_kernel_boot_path().to_str().unwrap()]) 313 .args(["--cmdline", "root=/dev/pmem0p1 console=ttyS0 quiet rw"]) 314 .args(["--console", "off"]) 315 .args([ 316 "--pmem", 317 format!( 318 "file={}", 319 guest.disk_config.disk(DiskType::OperatingSystem).unwrap() 320 ) 321 .as_str(), 322 ]); 323 324 measure_boot_time(c, control.test_timeout).unwrap() 325 }); 326 327 match r { 328 Ok(r) => r, 329 Err(_) => { 330 panic!("test failed!"); 331 } 332 } 333 } 334 335 pub fn performance_block_io(control: &PerformanceTestControl) -> f64 { 336 let test_timeout = control.test_timeout; 337 let num_queues = control.num_queues.unwrap(); 338 let fio_ops = control.fio_ops.as_ref().unwrap(); 339 340 let focal = UbuntuDiskConfig::new(FOCAL_IMAGE_NAME.to_string()); 341 let guest = performance_test_new_guest(Box::new(focal)); 342 let api_socket = guest 343 .tmp_dir 344 .as_path() 345 .join("cloud-hypervisor.sock") 346 .to_str() 347 .unwrap() 348 .to_string(); 349 350 let mut child = GuestCommand::new(&guest) 351 .args(["--cpus", &format!("boot={num_queues}")]) 352 .args(["--memory", "size=4G"]) 353 .args(["--kernel", direct_kernel_boot_path().to_str().unwrap()]) 354 .args(["--cmdline", DIRECT_KERNEL_BOOT_CMDLINE]) 355 .args([ 356 "--disk", 357 format!( 358 "path={}", 359 guest.disk_config.disk(DiskType::OperatingSystem).unwrap() 360 ) 361 .as_str(), 362 format!( 363 "path={}", 364 guest.disk_config.disk(DiskType::CloudInit).unwrap() 365 ) 366 .as_str(), 367 format!("path={BLK_IO_TEST_IMG}").as_str(), 368 ]) 369 .default_net() 370 .args(["--api-socket", &api_socket]) 371 .capture_output() 372 .verbosity(VerbosityLevel::Warn) 373 .set_print_cmd(false) 374 .spawn() 375 .unwrap(); 376 377 let r = std::panic::catch_unwind(|| { 378 guest.wait_vm_boot(None).unwrap(); 379 380 let fio_command = format!( 381 "sudo fio --filename=/dev/vdc --name=test --output-format=json \ 382 --direct=1 --bs=4k --ioengine=io_uring --iodepth=64 \ 383 --rw={fio_ops} --runtime={test_timeout} --numjobs={num_queues}" 384 ); 385 let output = guest 386 .ssh_command(&fio_command) 387 .map_err(InfraError::SshCommand) 388 .unwrap(); 389 390 // Parse fio output 391 parse_fio_output(&output, fio_ops, num_queues).unwrap() 392 }); 393 394 let _ = child.kill(); 395 let output = child.wait_with_output().unwrap(); 396 397 match r { 398 Ok(r) => r, 399 Err(e) => { 400 handle_child_output(Err(e), &output); 401 panic!("test failed!"); 402 } 403 } 404 } 405 406 #[cfg(test)] 407 mod tests { 408 use super::*; 409 410 #[test] 411 fn test_parse_iperf3_output() { 412 let output = r#" 413 { 414 "end": { 415 "sum_sent": { 416 "start": 0, 417 "end": 5.000196, 418 "seconds": 5.000196, 419 "bytes": 14973836248, 420 "bits_per_second": 23957198874.604115, 421 "retransmits": 0, 422 "sender": false 423 } 424 } 425 } 426 "#; 427 assert_eq!( 428 parse_iperf3_output(output.as_bytes(), true).unwrap(), 429 23957198874.604115 430 ); 431 432 let output = r#" 433 { 434 "end": { 435 "sum_received": { 436 "start": 0, 437 "end": 5.000626, 438 "seconds": 5.000626, 439 "bytes": 24703557800, 440 "bits_per_second": 39520744482.79, 441 "sender": true 442 } 443 } 444 } 445 "#; 446 assert_eq!( 447 parse_iperf3_output(output.as_bytes(), false).unwrap(), 448 39520744482.79 449 ); 450 } 451 452 #[test] 453 fn test_parse_ethr_latency_output() { 454 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"} 455 {"Time":"2022-02-08T03:52:51Z","Title":"","Type":"INFO","Message":"Running latency test: 1000, 1"} 456 {"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"} 457 {"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"} 458 {"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"}"#; 459 460 let ret = parse_ethr_latency_output(output.as_bytes()).unwrap(); 461 let reference = vec![80.712_f64, 79.826_f64, 78.239_f64]; 462 assert_eq!(ret, reference); 463 } 464 465 #[test] 466 fn test_parse_boot_time_output() { 467 let output = r#" 468 cloud-hypervisor: 161.167103ms: <vcpu0> INFO:vmm/src/vm.rs:392 -- [Debug I/O port: Kernel code 0x40] 0.132 seconds 469 cloud-hypervisor: 613.57361ms: <vcpu0> INFO:vmm/src/vm.rs:392 -- [Debug I/O port: Kernel code 0x41] 0.5845 seconds 470 "#; 471 472 assert_eq!(parse_boot_time_output(output.as_bytes()).unwrap(), 0.4525); 473 } 474 475 #[test] 476 fn test_parse_fio_output() { 477 let output = r#" 478 { 479 "jobs" : [ 480 { 481 "read" : { 482 "io_bytes" : 1965273088, 483 "io_kbytes" : 1919212, 484 "bw_bytes" : 392976022, 485 "bw" : 383765, 486 "iops" : 95941.411718, 487 "runtime" : 5001, 488 "total_ios" : 479803, 489 "short_ios" : 0, 490 "drop_ios" : 0 491 } 492 } 493 ] 494 } 495 "#; 496 497 let bps = 1965273088_f64 / (5001_f64 / 1000_f64); 498 assert_eq!( 499 parse_fio_output(output, &FioOps::RandomRead, 1).unwrap(), 500 bps 501 ); 502 assert_eq!(parse_fio_output(output, &FioOps::Read, 1).unwrap(), bps); 503 504 let output = r#" 505 { 506 "jobs" : [ 507 { 508 "write" : { 509 "io_bytes" : 1172783104, 510 "io_kbytes" : 1145296, 511 "bw_bytes" : 234462835, 512 "bw" : 228967, 513 "iops" : 57241.903239, 514 "runtime" : 5002, 515 "total_ios" : 286324, 516 "short_ios" : 0, 517 "drop_ios" : 0 518 } 519 }, 520 { 521 "write" : { 522 "io_bytes" : 1172234240, 523 "io_kbytes" : 1144760, 524 "bw_bytes" : 234353106, 525 "bw" : 228860, 526 "iops" : 57215.113954, 527 "runtime" : 5002, 528 "total_ios" : 286190, 529 "short_ios" : 0, 530 "drop_ios" : 0 531 } 532 } 533 ] 534 } 535 "#; 536 537 let bps = 1172783104_f64 / (5002_f64 / 1000_f64) + 1172234240_f64 / (5002_f64 / 1000_f64); 538 assert_eq!( 539 parse_fio_output(output, &FioOps::RandomWrite, 2).unwrap(), 540 bps 541 ); 542 assert_eq!(parse_fio_output(output, &FioOps::Write, 2).unwrap(), bps); 543 } 544 } 545