From mboxrd@z Thu Jan 1 00:00:00 1970 Received: by 2002:a17:906:33ce:b0:9d0:bf65:29fa with SMTP id w14csp321943eja; Thu, 2 Nov 2023 04:44:49 -0700 (PDT) X-Google-Smtp-Source: AGHT+IFwoBZQQ75B9GAr0BpRUcqBo1Gvc+hWdDt/oLfqqqJDwDl8GEvlFwSIfILMgslVj/3gCcBJ X-Received: by 2002:a67:c083:0:b0:457:c17a:d34 with SMTP id x3-20020a67c083000000b00457c17a0d34mr13142484vsi.2.1698925489032; Thu, 02 Nov 2023 04:44:49 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1698925489; cv=none; d=google.com; s=arc-20160816; b=RtdjUU9eArqLCrzZ7rBl/ZjoMvHo8604iZ6v9E+qDDu5doSEbmZXb74+qzE9WeAUz7 rbzoJeEkUV9GQperVHz5FTWoKYBnZRmz0eH2YfBJzi3zDn4Z2HdNje5vJTq5194612mK Ge+k3dLIwmaIZwqTePH9bHRSfWTIa3s84wULZsXZ1M/uek4ik4+rYnhYEF0W9dkCcM81 YagboqlXLm/ZktUrCNE0f9F7Bj9j/GRzrDXzuYBR6kdoGY276ja2GJMv5w4mgVbXxpTz DM+XL4sSmhxMlUFY8hSZfnbE5ffEmMl/1Stgb4zJw/g6kgFjo2/9RnxHMV6kV0qCcNlC 4HIg== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=sender:errors-to:list-subscribe:list-help:list-post:list-archive :list-unsubscribe:list-id:precedence:content-transfer-encoding :mime-version:references:in-reply-to:message-id:date:subject:cc:to :from:dkim-signature; bh=Wlltny6SsZfybCdSb+V6HIflnOr0x+IHQz2evKolZpE=; fh=T4EM+6jbLn5eRwObk7JR2S+dK3nM2HMDfFhJxfrmv8w=; b=ZEBCHG5f3xpfwukQL5z+YvTtalvMLLC/+uo0xKt5OZeZBVdAtBcgb2OUiRtIO8P4G9 D3QPfqUAE4SA/9LQZA6pQBGtF2gdRRrhC3Er2MbJXU+XEQ/48g0ES/UTLhDesKxVhEKX 8MHqG/TztlQayR4uJv+xkcjKwv2H5EaMO5e7SYOIRQwNKKFKSH886FYTW723b76CIiIJ X9TOkl7iEfNtwtt9IgNjwOOaKcfXqfpLJkLVJVy4fMKRRb877laCsp2wX83AZL7AxVRW lJriFqtbiMHx13LdPTDrwGyt1r7Q5PPq/69ZeSAixssB8xJ6JVCo/XcG2bjQ6cOiEoxx upzg== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@redhat.com header.s=mimecast20190719 header.b=eDFgP+rA; spf=pass (google.com: domain of qemu-arm-bounces+alex.bennee=linaro.org@nongnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom="qemu-arm-bounces+alex.bennee=linaro.org@nongnu.org"; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=redhat.com Return-Path: Received: from lists.gnu.org (lists.gnu.org. [209.51.188.17]) by mx.google.com with ESMTPS id u1-20020ac858c1000000b004181cc21b33si4168106qta.232.2023.11.02.04.44.48 for (version=TLS1_2 cipher=ECDHE-ECDSA-CHACHA20-POLY1305 bits=256/256); Thu, 02 Nov 2023 04:44:49 -0700 (PDT) Received-SPF: pass (google.com: domain of qemu-arm-bounces+alex.bennee=linaro.org@nongnu.org designates 209.51.188.17 as permitted sender) client-ip=209.51.188.17; Authentication-Results: mx.google.com; dkim=pass header.i=@redhat.com header.s=mimecast20190719 header.b=eDFgP+rA; spf=pass (google.com: domain of qemu-arm-bounces+alex.bennee=linaro.org@nongnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom="qemu-arm-bounces+alex.bennee=linaro.org@nongnu.org"; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=redhat.com Received: from localhost ([::1] helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1qyW7I-0007zD-Ac; Thu, 02 Nov 2023 07:44:04 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1qyW6k-00056m-Mb for qemu-arm@nongnu.org; Thu, 02 Nov 2023 07:43:30 -0400 Received: from us-smtp-delivery-124.mimecast.com ([170.10.133.124]) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1qyW6Y-0005rL-Jj for qemu-arm@nongnu.org; Thu, 02 Nov 2023 07:43:30 -0400 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1698925397; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=Wlltny6SsZfybCdSb+V6HIflnOr0x+IHQz2evKolZpE=; b=eDFgP+rAwctmVYXTBtP6+0oXbzylc9cMncPOeU0QdVUTHs+2zOdU6h9uHnt4ZU2KCrIxPe FcEZjjqT3+YVF7U3wqjSdNbxpy9gaEeokI3IHjsw9rq/12Wl+n7MbdBELI2//oP/D9NJu/ P84uX7+wek7X6LjMq187eubO3OrU4dk= Received: from mimecast-mx02.redhat.com (mx-ext.redhat.com [66.187.233.73]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.3, cipher=TLS_AES_256_GCM_SHA384) id us-mta-694-6wX--IUaOcS-1KThQNJqaQ-1; Thu, 02 Nov 2023 07:43:15 -0400 X-MC-Unique: 6wX--IUaOcS-1KThQNJqaQ-1 Received: from smtp.corp.redhat.com (int-mx04.intmail.prod.int.rdu2.redhat.com [10.11.54.4]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id 7DD131C01E90; Thu, 2 Nov 2023 11:43:13 +0000 (UTC) Received: from secure.mitica (unknown [10.39.195.26]) by smtp.corp.redhat.com (Postfix) with ESMTP id 3D4C82026D4C; Thu, 2 Nov 2023 11:43:06 +0000 (UTC) From: Juan Quintela To: qemu-devel@nongnu.org Cc: Eric Farman , Laurent Vivier , David Gibson , qemu-block@nongnu.org, Stefan Hajnoczi , Marcel Apfelbaum , Kevin Wolf , David Hildenbrand , Samuel Thibault , qemu-s390x@nongnu.org, Richard Henderson , Leonardo Bras , Corey Minyard , Ilya Leoshkevich , =?UTF-8?q?Marc-Andr=C3=A9=20Lureau?= , Markus Armbruster , Christian Borntraeger , Eduardo Habkost , Paolo Bonzini , qemu-ppc@nongnu.org, "Michael S. Tsirkin" , Peter Maydell , Halil Pasic , Gerd Hoffmann , =?UTF-8?q?C=C3=A9dric=20Le=20Goater?= , Li Zhijian , Eric Blake , "Denis V. Lunev" , Hanna Reitz , Fabiano Rosas , Stefan Berger , qemu-arm@nongnu.org, Daniel Henrique Barboza , Thomas Huth , Corey Minyard , John Snow , Jeff Cody , Peter Xu , Nicholas Piggin , Juan Quintela , Harsh Prateek Bora , Jason Wang , =?UTF-8?q?Daniel=20P=2E=20Berrang=C3=A9?= , Stefan Weil , Mark Cave-Ayland , Fam Zheng Subject: [PULL 17/40] migration: Add per vmstate downtime tracepoints Date: Thu, 2 Nov 2023 12:40:31 +0100 Message-ID: <20231102114054.44360-18-quintela@redhat.com> In-Reply-To: <20231102114054.44360-1-quintela@redhat.com> References: <20231102114054.44360-1-quintela@redhat.com> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Scanned-By: MIMEDefang 3.4.1 on 10.11.54.4 Received-SPF: pass client-ip=170.10.133.124; envelope-from=quintela@redhat.com; helo=us-smtp-delivery-124.mimecast.com X-Spam_score_int: -24 X-Spam_score: -2.5 X-Spam_bar: -- X-Spam_report: (-2.5 / 5.0 requ) BAYES_00=-1.9, DKIMWL_WL_HIGH=-0.393, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, RCVD_IN_DNSWL_NONE=-0.0001, RCVD_IN_MSPIKE_H3=0.001, RCVD_IN_MSPIKE_WL=0.001, SPF_HELO_NONE=0.001, SPF_PASS=-0.001, T_SCC_BODY_TEXT_LINE=-0.01 autolearn=ham autolearn_force=no X-Spam_action: no action X-BeenThere: qemu-arm@nongnu.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: qemu-arm-bounces+alex.bennee=linaro.org@nongnu.org Sender: qemu-arm-bounces+alex.bennee=linaro.org@nongnu.org X-TUID: EKcImDufQzZm From: Peter Xu We have a bunch of savevm_section* tracepoints, they're good to analyze migration stream, but not always suitable if someone would like to analyze the migration downtime. Two major problems: - savevm_section* tracepoints are dumping all sections, we only care about the sections that contribute to the downtime - They don't have an identifier to show the type of sections, so no way to filter downtime information either easily. We can add type into the tracepoints, but instead of doing so, this patch kept them untouched, instead of adding a bunch of downtime specific tracepoints, so one can enable "vmstate_downtime*" tracepoints and get a full picture of how the downtime is distributed across iterative and non-iterative vmstate save/load. Note that here both save() and load() need to be traced, because both of them may contribute to the downtime. The contribution is not a simple "add them together", though: consider when the src is doing a save() of device1 while the dest can be load()ing for device2, so they can happen concurrently. Tracking both sides make sense because device load() and save() can be imbalanced, one device can save() super fast, but load() super slow, vice versa. We can't figure that out without tracing both. Signed-off-by: Peter Xu Reviewed-by: Juan Quintela Signed-off-by: Juan Quintela Message-ID: <20231030163346.765724-4-peterx@redhat.com> --- migration/savevm.c | 49 ++++++++++++++++++++++++++++++++++++++---- migration/trace-events | 2 ++ 2 files changed, 47 insertions(+), 4 deletions(-) diff --git a/migration/savevm.c b/migration/savevm.c index 2095ddd6f8..99ce42b6f3 100644 --- a/migration/savevm.c +++ b/migration/savevm.c @@ -1491,6 +1491,7 @@ void qemu_savevm_state_complete_postcopy(QEMUFile *f) static int qemu_savevm_state_complete_precopy_iterable(QEMUFile *f, bool in_postcopy) { + int64_t start_ts_each, end_ts_each; SaveStateEntry *se; int ret; @@ -1507,6 +1508,8 @@ int qemu_savevm_state_complete_precopy_iterable(QEMUFile *f, bool in_postcopy) continue; } } + + start_ts_each = qemu_clock_get_us(QEMU_CLOCK_REALTIME); trace_savevm_section_start(se->idstr, se->section_id); save_section_header(f, se, QEMU_VM_SECTION_END); @@ -1518,6 +1521,9 @@ int qemu_savevm_state_complete_precopy_iterable(QEMUFile *f, bool in_postcopy) qemu_file_set_error(f, ret); return -1; } + end_ts_each = qemu_clock_get_us(QEMU_CLOCK_REALTIME); + trace_vmstate_downtime_save("iterable", se->idstr, se->instance_id, + end_ts_each - start_ts_each); } return 0; @@ -1528,6 +1534,7 @@ int qemu_savevm_state_complete_precopy_non_iterable(QEMUFile *f, bool inactivate_disks) { MigrationState *ms = migrate_get_current(); + int64_t start_ts_each, end_ts_each; JSONWriter *vmdesc = ms->vmdesc; int vmdesc_len; SaveStateEntry *se; @@ -1539,11 +1546,17 @@ int qemu_savevm_state_complete_precopy_non_iterable(QEMUFile *f, continue; } + start_ts_each = qemu_clock_get_us(QEMU_CLOCK_REALTIME); + ret = vmstate_save(f, se, vmdesc); if (ret) { qemu_file_set_error(f, ret); return ret; } + + end_ts_each = qemu_clock_get_us(QEMU_CLOCK_REALTIME); + trace_vmstate_downtime_save("non-iterable", se->idstr, se->instance_id, + end_ts_each - start_ts_each); } if (inactivate_disks) { @@ -2537,9 +2550,12 @@ static bool check_section_footer(QEMUFile *f, SaveStateEntry *se) } static int -qemu_loadvm_section_start_full(QEMUFile *f, MigrationIncomingState *mis) +qemu_loadvm_section_start_full(QEMUFile *f, MigrationIncomingState *mis, + uint8_t type) { + bool trace_downtime = (type == QEMU_VM_SECTION_FULL); uint32_t instance_id, version_id, section_id; + int64_t start_ts, end_ts; SaveStateEntry *se; char idstr[256]; int ret; @@ -2588,12 +2604,23 @@ qemu_loadvm_section_start_full(QEMUFile *f, MigrationIncomingState *mis) return -EINVAL; } + if (trace_downtime) { + start_ts = qemu_clock_get_us(QEMU_CLOCK_REALTIME); + } + ret = vmstate_load(f, se); if (ret < 0) { error_report("error while loading state for instance 0x%"PRIx32" of" " device '%s'", instance_id, idstr); return ret; } + + if (trace_downtime) { + end_ts = qemu_clock_get_us(QEMU_CLOCK_REALTIME); + trace_vmstate_downtime_load("non-iterable", se->idstr, + se->instance_id, end_ts - start_ts); + } + if (!check_section_footer(f, se)) { return -EINVAL; } @@ -2602,8 +2629,11 @@ qemu_loadvm_section_start_full(QEMUFile *f, MigrationIncomingState *mis) } static int -qemu_loadvm_section_part_end(QEMUFile *f, MigrationIncomingState *mis) +qemu_loadvm_section_part_end(QEMUFile *f, MigrationIncomingState *mis, + uint8_t type) { + bool trace_downtime = (type == QEMU_VM_SECTION_END); + int64_t start_ts, end_ts; uint32_t section_id; SaveStateEntry *se; int ret; @@ -2628,12 +2658,23 @@ qemu_loadvm_section_part_end(QEMUFile *f, MigrationIncomingState *mis) return -EINVAL; } + if (trace_downtime) { + start_ts = qemu_clock_get_us(QEMU_CLOCK_REALTIME); + } + ret = vmstate_load(f, se); if (ret < 0) { error_report("error while loading state section id %d(%s)", section_id, se->idstr); return ret; } + + if (trace_downtime) { + end_ts = qemu_clock_get_us(QEMU_CLOCK_REALTIME); + trace_vmstate_downtime_load("iterable", se->idstr, + se->instance_id, end_ts - start_ts); + } + if (!check_section_footer(f, se)) { return -EINVAL; } @@ -2822,14 +2863,14 @@ retry: switch (section_type) { case QEMU_VM_SECTION_START: case QEMU_VM_SECTION_FULL: - ret = qemu_loadvm_section_start_full(f, mis); + ret = qemu_loadvm_section_start_full(f, mis, section_type); if (ret < 0) { goto out; } break; case QEMU_VM_SECTION_PART: case QEMU_VM_SECTION_END: - ret = qemu_loadvm_section_part_end(f, mis); + ret = qemu_loadvm_section_part_end(f, mis, section_type); if (ret < 0) { goto out; } diff --git a/migration/trace-events b/migration/trace-events index fa9486dffe..5820add1f3 100644 --- a/migration/trace-events +++ b/migration/trace-events @@ -48,6 +48,8 @@ savevm_state_cleanup(void) "" savevm_state_complete_precopy(void) "" vmstate_save(const char *idstr, const char *vmsd_name) "%s, %s" vmstate_load(const char *idstr, const char *vmsd_name) "%s, %s" +vmstate_downtime_save(const char *type, const char *idstr, uint32_t instance_id, int64_t downtime) "type=%s idstr=%s instance_id=%d downtime=%"PRIi64 +vmstate_downtime_load(const char *type, const char *idstr, uint32_t instance_id, int64_t downtime) "type=%s idstr=%s instance_id=%d downtime=%"PRIi64 postcopy_pause_incoming(void) "" postcopy_pause_incoming_continued(void) "" postcopy_page_req_sync(void *host_addr) "sync page req %p" -- 2.41.0