Re: [Qemu-devel] [RFC PATCH v2 07/12] mc: introduce additional QMP statistics for micro-checkpointing

["Michael R. Hines" <mrhines@linux.vnet.ibm.com>]

On 03/12/2014 05:59 AM, Juan Quintela wrote:
> mrhines@linux.vnet.ibm.com wrote:
>> From: "Michael R. Hines" <mrhines@us.ibm.com>
>>
>> MC provides a lot of new information, including the same RAM statistics
>> that ordinary migration does, so we centralize a lot of that printing
>> code into a common function so that the QMP printing statements don't
>> get duplicated too much.
>>
>> We also introduce a new MCStats structure (like MigrationStats) due
>> to the large number of non-migration related statistics - don't want
>> to confuse migration and MC too much, so let's keep them separate for now.
>>
>> Signed-off-by: Michael R. Hines <mrhines@us.ibm.com>
> We can add the non-mc stats if you split them.  And you get a smaller
> series.

Well, the MIG_STATE_COMPLETED and the MIG_STATE_ACTIVE cleanup
is removing a ton of duplicated code anyway - that needed to be cleaned
up regardless.

But, for the MC-related statistics, this really is a completely new state
in the migration state machine with so many new statistics - I don't think
they belong in the MigrationInfo structure at all......

- Michael

> Later, Juan.
>
>
>> ---
>>   hmp.c                         | 17 +++++++++
>>   include/migration/migration.h |  6 +++
>>   migration.c                   | 86 ++++++++++++++++++++++++++-----------------
>>   qapi-schema.json              | 33 +++++++++++++++++
>>   4 files changed, 109 insertions(+), 33 deletions(-)
>>
>> diff --git a/hmp.c b/hmp.c
>> index 1af0809..edf062e 100644
>> --- a/hmp.c
>> +++ b/hmp.c
>> @@ -203,6 +203,23 @@ void hmp_info_migrate(Monitor *mon, const QDict *qdict)
>>                          info->disk->total >> 10);
>>       }
>>   
>> +    if (info->has_mc) {
>> +        monitor_printf(mon, "checkpoints: %" PRIu64 "\n",
>> +                       info->mc->checkpoints);
>> +        monitor_printf(mon, "xmit_time: %" PRIu64 " ms\n",
>> +                       info->mc->xmit_time);
>> +        monitor_printf(mon, "log_dirty_time: %" PRIu64 " ms\n",
>> +                       info->mc->log_dirty_time);
>> +        monitor_printf(mon, "migration_bitmap_time: %" PRIu64 " ms\n",
>> +                       info->mc->migration_bitmap_time);
>> +        monitor_printf(mon, "ram_copy_time: %" PRIu64 " ms\n",
>> +                       info->mc->ram_copy_time);
>> +        monitor_printf(mon, "copy_mbps: %0.2f mbps\n",
>> +                       info->mc->copy_mbps);
>> +        monitor_printf(mon, "throughput: %0.2f mbps\n",
>> +                       info->mc->mbps);
>> +    }
>> +
>>       if (info->has_xbzrle_cache) {
>>           monitor_printf(mon, "cache size: %" PRIu64 " bytes\n",
>>                          info->xbzrle_cache->cache_size);
>> diff --git a/include/migration/migration.h b/include/migration/migration.h
>> index e876a2c..f18ff5e 100644
>> --- a/include/migration/migration.h
>> +++ b/include/migration/migration.h
>> @@ -53,14 +53,20 @@ struct MigrationState
>>       int state;
>>       MigrationParams params;
>>       double mbps;
>> +    double copy_mbps;
>>       int64_t total_time;
>>       int64_t downtime;
>>       int64_t expected_downtime;
>> +    int64_t xmit_time;
>> +    int64_t ram_copy_time;
>> +    int64_t log_dirty_time;
>> +    int64_t bitmap_time;
>>       int64_t dirty_pages_rate;
>>       int64_t dirty_bytes_rate;
>>       bool enabled_capabilities[MIGRATION_CAPABILITY_MAX];
>>       int64_t xbzrle_cache_size;
>>       int64_t setup_time;
>> +    int64_t checkpoints;
>>   };
>>   
>>   void process_incoming_migration(QEMUFile *f);
>> diff --git a/migration.c b/migration.c
>> index f42dae4..0ccbeaa 100644
>> --- a/migration.c
>> +++ b/migration.c
>> @@ -59,7 +59,6 @@ MigrationState *migrate_get_current(void)
>>           .state = MIG_STATE_NONE,
>>           .bandwidth_limit = MAX_THROTTLE,
>>           .xbzrle_cache_size = DEFAULT_MIGRATE_CACHE_SIZE,
>> -        .mbps = -1,
>>       };
>>   
>>       return &current_migration;
>> @@ -173,6 +172,31 @@ static void get_xbzrle_cache_stats(MigrationInfo *info)
>>       }
>>   }
>>   
>> +static void get_ram_stats(MigrationState *s, MigrationInfo *info)
>> +{
>> +    info->has_total_time = true;
>> +    info->total_time = qemu_clock_get_ms(QEMU_CLOCK_REALTIME)
>> +        - s->total_time;
>> +
>> +    info->has_ram = true;
>> +    info->ram = g_malloc0(sizeof(*info->ram));
>> +    info->ram->transferred = ram_bytes_transferred();
>> +    info->ram->total = ram_bytes_total();
>> +    info->ram->duplicate = dup_mig_pages_transferred();
>> +    info->ram->skipped = skipped_mig_pages_transferred();
>> +    info->ram->normal = norm_mig_pages_transferred();
>> +    info->ram->normal_bytes = norm_mig_bytes_transferred();
>> +    info->ram->mbps = s->mbps;
>> +
>> +    if (blk_mig_active()) {
>> +        info->has_disk = true;
>> +        info->disk = g_malloc0(sizeof(*info->disk));
>> +        info->disk->transferred = blk_mig_bytes_transferred();
>> +        info->disk->remaining = blk_mig_bytes_remaining();
>> +        info->disk->total = blk_mig_bytes_total();
>> +    }
>> +}
>> +
>>   MigrationInfo *qmp_query_migrate(Error **errp)
>>   {
>>       MigrationInfo *info = g_malloc0(sizeof(*info));
>> @@ -199,26 +223,8 @@ MigrationInfo *qmp_query_migrate(Error **errp)
>>           info->has_setup_time = true;
>>           info->setup_time = s->setup_time;
>>   
>> -        info->has_ram = true;
>> -        info->ram = g_malloc0(sizeof(*info->ram));
>> -        info->ram->transferred = ram_bytes_transferred();
>> -        info->ram->remaining = ram_bytes_remaining();
>> -        info->ram->total = ram_bytes_total();
>> -        info->ram->duplicate = dup_mig_pages_transferred();
>> -        info->ram->skipped = skipped_mig_pages_transferred();
>> -        info->ram->normal = norm_mig_pages_transferred();
>> -        info->ram->normal_bytes = norm_mig_bytes_transferred();
>> +        get_ram_stats(s, info);
>>           info->ram->dirty_pages_rate = s->dirty_pages_rate;
>> -        info->ram->mbps = s->mbps;
>> -
>> -        if (blk_mig_active()) {
>> -            info->has_disk = true;
>> -            info->disk = g_malloc0(sizeof(*info->disk));
>> -            info->disk->transferred = blk_mig_bytes_transferred();
>> -            info->disk->remaining = blk_mig_bytes_remaining();
>> -            info->disk->total = blk_mig_bytes_total();
>> -        }
>> -
>>           get_xbzrle_cache_stats(info);
>>           break;
>>       case MIG_STATE_COMPLETED:
>> @@ -227,22 +233,37 @@ MigrationInfo *qmp_query_migrate(Error **errp)
>>           info->has_status = true;
>>           info->status = g_strdup("completed");
>>           info->has_total_time = true;
>> -        info->total_time = s->total_time;
>> +        info->total_time = qemu_clock_get_ms(QEMU_CLOCK_REALTIME)
>> +            - s->total_time;
>>           info->has_downtime = true;
>>           info->downtime = s->downtime;
>>           info->has_setup_time = true;
>>           info->setup_time = s->setup_time;
>>   
>> -        info->has_ram = true;
>> -        info->ram = g_malloc0(sizeof(*info->ram));
>> -        info->ram->transferred = ram_bytes_transferred();
>> -        info->ram->remaining = 0;
>> -        info->ram->total = ram_bytes_total();
>> -        info->ram->duplicate = dup_mig_pages_transferred();
>> -        info->ram->skipped = skipped_mig_pages_transferred();
>> -        info->ram->normal = norm_mig_pages_transferred();
>> -        info->ram->normal_bytes = norm_mig_bytes_transferred();
>> -        info->ram->mbps = s->mbps;
>> +        get_ram_stats(s, info);
>> +        break;
>> +    case MIG_STATE_CHECKPOINTING:
>> +        info->has_status = true;
>> +        info->status = g_strdup("checkpointing");
>> +        info->has_setup_time = true;
>> +        info->setup_time = s->setup_time;
>> +        info->has_downtime = true;
>> +        info->downtime = s->downtime;
>> +
>> +        get_ram_stats(s, info);
>> +        info->ram->dirty_pages_rate = s->dirty_pages_rate;
>> +        get_xbzrle_cache_stats(info);
>> +
>> +
>> +        info->has_mc = true;
>> +        info->mc = g_malloc0(sizeof(*info->mc));
>> +        info->mc->xmit_time = s->xmit_time;
>> +        info->mc->log_dirty_time = s->log_dirty_time;
>> +        info->mc->migration_bitmap_time = s->bitmap_time;
>> +        info->mc->ram_copy_time = s->ram_copy_time;
>> +        info->mc->copy_mbps = s->copy_mbps;
>> +        info->mc->mbps = s->mbps;
>> +        info->mc->checkpoints = s->checkpoints;
>>           break;
>>       case MIG_STATE_ERROR:
>>           info->has_status = true;
>> @@ -646,8 +667,7 @@ static void *migration_thread(void *opaque)
>>               double bandwidth = transferred_bytes / time_spent;
>>               max_size = bandwidth * migrate_max_downtime() / 1000000;
>>   
>> -            s->mbps = time_spent ? (((double) transferred_bytes * 8.0) /
>> -                    ((double) time_spent / 1000.0)) / 1000.0 / 1000.0 : -1;
>> +            s->mbps = MBPS(transferred_bytes, time_spent);
>>   
>>               DPRINTF("transferred %" PRIu64 " time_spent %" PRIu64
>>                       " bandwidth %g max_size %" PRId64 "\n",
>> diff --git a/qapi-schema.json b/qapi-schema.json
>> index 3c2ee4d..7306adc 100644
>> --- a/qapi-schema.json
>> +++ b/qapi-schema.json
>> @@ -603,6 +603,36 @@
>>              'cache-miss': 'int', 'overflow': 'int' } }
>>   
>>   ##
>> +# @MCStats
>> +#
>> +# Detailed Micro Checkpointing (MC) statistics
>> +#
>> +# @mbps: throughput of transmitting last MC
>> +#
>> +# @xmit-time: milliseconds to transmit last MC
>> +#
>> +# @log-dirty-time: milliseconds to GET_LOG_DIRTY for last MC
>> +#
>> +# @migration-bitmap-time: milliseconds to prepare dirty bitmap for last MC
>> +#
>> +# @ram-copy-time: milliseconds to ram_save_live() last MC to staging memory
>> +#
>> +# @copy-mbps: throughput of ram_save_live() to staging memory for last MC
>> +#
>> +# @checkpoints: cummulative total number of MCs generated
>> +#
>> +# Since: 2.x
>> +##
>> +{ 'type': 'MCStats',
>> +  'data': {'mbps': 'number',
>> +           'xmit-time': 'uint64',
>> +           'log-dirty-time': 'uint64',
>> +           'migration-bitmap-time': 'uint64',
>> +           'ram-copy-time': 'uint64',
>> +           'checkpoints' : 'uint64',
>> +           'copy-mbps': 'number' }}
>> +
>> +##
>>   # @MigrationInfo
>>   #
>>   # Information about current migration process.
>> @@ -624,6 +654,8 @@
>>   #                migration statistics, only returned if XBZRLE feature is on and
>>   #                status is 'active' or 'completed' (since 1.2)
>>   #
>> +# @mc: #options @MCStats containing details Micro-Checkpointing statistics
>> +#
>>   # @total-time: #optional total amount of milliseconds since migration started.
>>   #        If migration has ended, it returns the total migration
>>   #        time. (since 1.2)
>> @@ -648,6 +680,7 @@
>>     'data': {'*status': 'str', '*ram': 'MigrationStats',
>>              '*disk': 'MigrationStats',
>>              '*xbzrle-cache': 'XBZRLECacheStats',
>> +           '*mc': 'MCStats',
>>              '*total-time': 'int',
>>              '*expected-downtime': 'int',
>>              '*downtime': 'int',