diff mbox series

[v2] migration: using trace_ to replace DPRINTF

Message ID 1603176121-750-1-git-send-email-yubihong@huawei.com
State Accepted
Commit fe80c0241dc493a66a0805fe016ed28505492fed
Headers show
Series [v2] migration: using trace_ to replace DPRINTF | expand

Commit Message

Bihong Yu Oct. 20, 2020, 6:42 a.m. UTC
Signed-off-by: Bihong Yu <yubihong@huawei.com>
---
 migration/block.c      | 36 ++++++++++++++++++------------------
 migration/page_cache.c | 13 +++----------
 migration/trace-events | 13 +++++++++++++
 3 files changed, 34 insertions(+), 28 deletions(-)

Comments

Philippe Mathieu-Daudé Oct. 20, 2020, 6:54 a.m. UTC | #1
On 10/20/20 8:42 AM, Bihong Yu wrote:
> Signed-off-by: Bihong Yu <yubihong@huawei.com>

> ---

>   migration/block.c      | 36 ++++++++++++++++++------------------

>   migration/page_cache.c | 13 +++----------

>   migration/trace-events | 13 +++++++++++++

>   3 files changed, 34 insertions(+), 28 deletions(-)

> 

> diff --git a/migration/block.c b/migration/block.c

> index 273392b..1e76a9f 100644

> --- a/migration/block.c

> +++ b/migration/block.c

> @@ -26,6 +26,7 @@

>   #include "qemu-file.h"

>   #include "migration/vmstate.h"

>   #include "sysemu/block-backend.h"

> +#include "trace.h"

>   

>   #define BLK_MIG_BLOCK_SIZE           (1 << 20)

>   #define BDRV_SECTORS_PER_DIRTY_CHUNK (BLK_MIG_BLOCK_SIZE >> BDRV_SECTOR_BITS)

> @@ -434,10 +435,9 @@ static int init_blk_migration(QEMUFile *f)

>           block_mig_state.total_sector_sum += sectors;

>   

>           if (bmds->shared_base) {

> -            DPRINTF("Start migration for %s with shared base image\n",

> -                    bdrv_get_device_name(bs));

> +            trace_init_blk_migration_shared(bdrv_get_device_name(bs));

>           } else {

> -            DPRINTF("Start full migration for %s\n", bdrv_get_device_name(bs));

> +            trace_init_blk_migration_full(bdrv_get_device_name(bs));

>           }

>   

>           QSIMPLEQ_INSERT_TAIL(&block_mig_state.bmds_list, bmds, entry);

> @@ -592,7 +592,7 @@ static int mig_save_device_dirty(QEMUFile *f, BlkMigDevState *bmds,

>       return (bmds->cur_dirty >= bmds->total_sectors);

>   

>   error:

> -    DPRINTF("Error reading sector %" PRId64 "\n", sector);

> +    trace_mig_save_device_dirty(sector);

>       g_free(blk->buf);

>       g_free(blk);

>       return ret;

> @@ -628,9 +628,9 @@ static int flush_blks(QEMUFile *f)

>       BlkMigBlock *blk;

>       int ret = 0;

>   

> -    DPRINTF("%s Enter submitted %d read_done %d transferred %d\n",

> -            __func__, block_mig_state.submitted, block_mig_state.read_done,

> -            block_mig_state.transferred);

> +    trace_flush_blks("Enter", block_mig_state.submitted,

> +                     block_mig_state.read_done,

> +                     block_mig_state.transferred);

>   

>       blk_mig_lock();

>       while ((blk = QSIMPLEQ_FIRST(&block_mig_state.blk_list)) != NULL) {

> @@ -656,9 +656,9 @@ static int flush_blks(QEMUFile *f)

>       }

>       blk_mig_unlock();

>   

> -    DPRINTF("%s Exit submitted %d read_done %d transferred %d\n", __func__,

> -            block_mig_state.submitted, block_mig_state.read_done,

> -            block_mig_state.transferred);

> +    trace_flush_blks("Exit", block_mig_state.submitted,

> +                     block_mig_state.read_done,

> +                     block_mig_state.transferred);

>       return ret;

>   }

>   

> @@ -727,8 +727,8 @@ static int block_save_setup(QEMUFile *f, void *opaque)

>   {

>       int ret;

>   

> -    DPRINTF("Enter save live setup submitted %d transferred %d\n",

> -            block_mig_state.submitted, block_mig_state.transferred);

> +    trace_migration_block_save("setup", block_mig_state.submitted,

> +                               block_mig_state.transferred);

>   

>       qemu_mutex_lock_iothread();

>       ret = init_blk_migration(f);

> @@ -759,8 +759,8 @@ static int block_save_iterate(QEMUFile *f, void *opaque)

>       int64_t last_ftell = qemu_ftell(f);

>       int64_t delta_ftell;

>   

> -    DPRINTF("Enter save live iterate submitted %d transferred %d\n",

> -            block_mig_state.submitted, block_mig_state.transferred);

> +    trace_migration_block_save("iterate", block_mig_state.submitted,

> +                               block_mig_state.transferred);

>   

>       ret = flush_blks(f);

>       if (ret) {

> @@ -825,8 +825,8 @@ static int block_save_complete(QEMUFile *f, void *opaque)

>   {

>       int ret;

>   

> -    DPRINTF("Enter save live complete submitted %d transferred %d\n",

> -            block_mig_state.submitted, block_mig_state.transferred);

> +    trace_migration_block_save("complete", block_mig_state.submitted,

> +                               block_mig_state.transferred);

>   

>       ret = flush_blks(f);

>       if (ret) {

> @@ -851,7 +851,7 @@ static int block_save_complete(QEMUFile *f, void *opaque)

>       /* report completion */

>       qemu_put_be64(f, (100 << BDRV_SECTOR_BITS) | BLK_MIG_FLAG_PROGRESS);

>   

> -    DPRINTF("Block migration completed\n");

> +    trace_migration_block_save_complete();

>   

>       qemu_put_be64(f, BLK_MIG_FLAG_EOS);

>   

> @@ -884,7 +884,7 @@ static void block_save_pending(QEMUFile *f, void *opaque, uint64_t max_size,

>           pending = max_size + BLK_MIG_BLOCK_SIZE;

>       }

>   

> -    DPRINTF("Enter save live pending  %" PRIu64 "\n", pending);

> +    trace_migration_block_save_pending(pending);

>       /* We don't do postcopy */

>       *res_precopy_only += pending;

>   }

> diff --git a/migration/page_cache.c b/migration/page_cache.c

> index 775582f..d554efa 100644

> --- a/migration/page_cache.c

> +++ b/migration/page_cache.c

> @@ -18,14 +18,7 @@

>   #include "qapi/error.h"

>   #include "qemu/host-utils.h"

>   #include "page_cache.h"

> -

> -#ifdef DEBUG_CACHE

> -#define DPRINTF(fmt, ...) \

> -    do { fprintf(stdout, "cache: " fmt, ## __VA_ARGS__); } while (0)

> -#else

> -#define DPRINTF(fmt, ...) \

> -    do { } while (0)

> -#endif

> +#include "trace.h"

>   

>   /* the page in cache will not be replaced in two cycles */

>   #define CACHED_PAGE_LIFETIME 2

> @@ -75,7 +68,7 @@ PageCache *cache_init(int64_t new_size, size_t page_size, Error **errp)

>       cache->num_items = 0;

>       cache->max_num_items = num_pages;

>   

> -    DPRINTF("Setting cache buckets to %" PRId64 "\n", cache->max_num_items);

> +    trace_cache_init(cache->max_num_items);

>   

>       /* We prefer not to abort if there is no memory */

>       cache->page_cache = g_try_malloc((cache->max_num_items) *

> @@ -169,7 +162,7 @@ int cache_insert(PageCache *cache, uint64_t addr, const uint8_t *pdata,

>       if (!it->it_data) {

>           it->it_data = g_try_malloc(cache->page_size);

>           if (!it->it_data) {

> -            DPRINTF("Error allocating page\n");

> +            trace_cache_insert();

>               return -1;

>           }

>           cache->num_items++;

> diff --git a/migration/trace-events b/migration/trace-events

> index 338f38b..094dbe4 100644

> --- a/migration/trace-events

> +++ b/migration/trace-events

> @@ -325,3 +325,16 @@ get_ramblock_vfn_hash(const char *idstr, uint64_t vfn, uint32_t crc) "ramblock n

>   calc_page_dirty_rate(const char *idstr, uint32_t new_crc, uint32_t old_crc) "ramblock name: %s, new crc: %" PRIu32 ", old crc: %" PRIu32

>   skip_sample_ramblock(const char *idstr, uint64_t ramblock_size) "ramblock name: %s, ramblock size: %" PRIu64

>   find_page_matched(const char *idstr) "ramblock %s addr or size changed"

> +

> +# block.c

> +init_blk_migration_shared(const char *blk_device_name) "Start migration for %s with shared base image"

> +init_blk_migration_full(const char *blk_device_name) "Start full migration for %s"

> +mig_save_device_dirty(int64_t sector) "Error reading sector %" PRId64

> +flush_blks(const char *action, int submitted, int read_done, int transferred) "%s submitted %d read_done %d transferred %d"


When using tracing, you usually start with a global pattern,
then slowly remove events until tracing the particular one
interesting you. As these all belong to the same subsystem,
please use "migration_block_" prefix for all.

> +migration_block_save(const char *mig_stage, int submitted, int transferred) "Enter save live %s submitted %d transferred %d"

> +migration_block_save_complete(void) "Block migration completed"

> +migration_block_save_pending(uint64_t pending) "Enter save live pending  %" PRIu64


These are good.

> +

> +# page_cache.c

> +cache_init(int64_t max_num_items) "Setting cache buckets to %" PRId64

> +cache_insert(void) "Error allocating page"


Please use "migration_block_" prefix here too.

Regards,

Phil.
Bihong Yu Oct. 20, 2020, 7:07 a.m. UTC | #2
On 2020/10/20 14:54, Philippe Mathieu-Daudé wrote:
> On 10/20/20 8:42 AM, Bihong Yu wrote:
>> Signed-off-by: Bihong Yu <yubihong@huawei.com>
>> ---
>>   migration/block.c      | 36 ++++++++++++++++++------------------
>>   migration/page_cache.c | 13 +++----------
>>   migration/trace-events | 13 +++++++++++++
>>   3 files changed, 34 insertions(+), 28 deletions(-)
>>
>> diff --git a/migration/block.c b/migration/block.c
>> index 273392b..1e76a9f 100644
>> --- a/migration/block.c
>> +++ b/migration/block.c
>> @@ -26,6 +26,7 @@
>>   #include "qemu-file.h"
>>   #include "migration/vmstate.h"
>>   #include "sysemu/block-backend.h"
>> +#include "trace.h"
>>     #define BLK_MIG_BLOCK_SIZE           (1 << 20)
>>   #define BDRV_SECTORS_PER_DIRTY_CHUNK (BLK_MIG_BLOCK_SIZE >> BDRV_SECTOR_BITS)
>> @@ -434,10 +435,9 @@ static int init_blk_migration(QEMUFile *f)
>>           block_mig_state.total_sector_sum += sectors;
>>             if (bmds->shared_base) {
>> -            DPRINTF("Start migration for %s with shared base image\n",
>> -                    bdrv_get_device_name(bs));
>> +            trace_init_blk_migration_shared(bdrv_get_device_name(bs));
>>           } else {
>> -            DPRINTF("Start full migration for %s\n", bdrv_get_device_name(bs));
>> +            trace_init_blk_migration_full(bdrv_get_device_name(bs));
>>           }
>>             QSIMPLEQ_INSERT_TAIL(&block_mig_state.bmds_list, bmds, entry);
>> @@ -592,7 +592,7 @@ static int mig_save_device_dirty(QEMUFile *f, BlkMigDevState *bmds,
>>       return (bmds->cur_dirty >= bmds->total_sectors);
>>     error:
>> -    DPRINTF("Error reading sector %" PRId64 "\n", sector);
>> +    trace_mig_save_device_dirty(sector);
>>       g_free(blk->buf);
>>       g_free(blk);
>>       return ret;
>> @@ -628,9 +628,9 @@ static int flush_blks(QEMUFile *f)
>>       BlkMigBlock *blk;
>>       int ret = 0;
>>   -    DPRINTF("%s Enter submitted %d read_done %d transferred %d\n",
>> -            __func__, block_mig_state.submitted, block_mig_state.read_done,
>> -            block_mig_state.transferred);
>> +    trace_flush_blks("Enter", block_mig_state.submitted,
>> +                     block_mig_state.read_done,
>> +                     block_mig_state.transferred);
>>         blk_mig_lock();
>>       while ((blk = QSIMPLEQ_FIRST(&block_mig_state.blk_list)) != NULL) {
>> @@ -656,9 +656,9 @@ static int flush_blks(QEMUFile *f)
>>       }
>>       blk_mig_unlock();
>>   -    DPRINTF("%s Exit submitted %d read_done %d transferred %d\n", __func__,
>> -            block_mig_state.submitted, block_mig_state.read_done,
>> -            block_mig_state.transferred);
>> +    trace_flush_blks("Exit", block_mig_state.submitted,
>> +                     block_mig_state.read_done,
>> +                     block_mig_state.transferred);
>>       return ret;
>>   }
>>   @@ -727,8 +727,8 @@ static int block_save_setup(QEMUFile *f, void *opaque)
>>   {
>>       int ret;
>>   -    DPRINTF("Enter save live setup submitted %d transferred %d\n",
>> -            block_mig_state.submitted, block_mig_state.transferred);
>> +    trace_migration_block_save("setup", block_mig_state.submitted,
>> +                               block_mig_state.transferred);
>>         qemu_mutex_lock_iothread();
>>       ret = init_blk_migration(f);
>> @@ -759,8 +759,8 @@ static int block_save_iterate(QEMUFile *f, void *opaque)
>>       int64_t last_ftell = qemu_ftell(f);
>>       int64_t delta_ftell;
>>   -    DPRINTF("Enter save live iterate submitted %d transferred %d\n",
>> -            block_mig_state.submitted, block_mig_state.transferred);
>> +    trace_migration_block_save("iterate", block_mig_state.submitted,
>> +                               block_mig_state.transferred);
>>         ret = flush_blks(f);
>>       if (ret) {
>> @@ -825,8 +825,8 @@ static int block_save_complete(QEMUFile *f, void *opaque)
>>   {
>>       int ret;
>>   -    DPRINTF("Enter save live complete submitted %d transferred %d\n",
>> -            block_mig_state.submitted, block_mig_state.transferred);
>> +    trace_migration_block_save("complete", block_mig_state.submitted,
>> +                               block_mig_state.transferred);
>>         ret = flush_blks(f);
>>       if (ret) {
>> @@ -851,7 +851,7 @@ static int block_save_complete(QEMUFile *f, void *opaque)
>>       /* report completion */
>>       qemu_put_be64(f, (100 << BDRV_SECTOR_BITS) | BLK_MIG_FLAG_PROGRESS);
>>   -    DPRINTF("Block migration completed\n");
>> +    trace_migration_block_save_complete();
>>         qemu_put_be64(f, BLK_MIG_FLAG_EOS);
>>   @@ -884,7 +884,7 @@ static void block_save_pending(QEMUFile *f, void *opaque, uint64_t max_size,
>>           pending = max_size + BLK_MIG_BLOCK_SIZE;
>>       }
>>   -    DPRINTF("Enter save live pending  %" PRIu64 "\n", pending);
>> +    trace_migration_block_save_pending(pending);
>>       /* We don't do postcopy */
>>       *res_precopy_only += pending;
>>   }
>> diff --git a/migration/page_cache.c b/migration/page_cache.c
>> index 775582f..d554efa 100644
>> --- a/migration/page_cache.c
>> +++ b/migration/page_cache.c
>> @@ -18,14 +18,7 @@
>>   #include "qapi/error.h"
>>   #include "qemu/host-utils.h"
>>   #include "page_cache.h"
>> -
>> -#ifdef DEBUG_CACHE
>> -#define DPRINTF(fmt, ...) \
>> -    do { fprintf(stdout, "cache: " fmt, ## __VA_ARGS__); } while (0)
>> -#else
>> -#define DPRINTF(fmt, ...) \
>> -    do { } while (0)
>> -#endif
>> +#include "trace.h"
>>     /* the page in cache will not be replaced in two cycles */
>>   #define CACHED_PAGE_LIFETIME 2
>> @@ -75,7 +68,7 @@ PageCache *cache_init(int64_t new_size, size_t page_size, Error **errp)
>>       cache->num_items = 0;
>>       cache->max_num_items = num_pages;
>>   -    DPRINTF("Setting cache buckets to %" PRId64 "\n", cache->max_num_items);
>> +    trace_cache_init(cache->max_num_items);
>>         /* We prefer not to abort if there is no memory */
>>       cache->page_cache = g_try_malloc((cache->max_num_items) *
>> @@ -169,7 +162,7 @@ int cache_insert(PageCache *cache, uint64_t addr, const uint8_t *pdata,
>>       if (!it->it_data) {
>>           it->it_data = g_try_malloc(cache->page_size);
>>           if (!it->it_data) {
>> -            DPRINTF("Error allocating page\n");
>> +            trace_cache_insert();
>>               return -1;
>>           }
>>           cache->num_items++;
>> diff --git a/migration/trace-events b/migration/trace-events
>> index 338f38b..094dbe4 100644
>> --- a/migration/trace-events
>> +++ b/migration/trace-events
>> @@ -325,3 +325,16 @@ get_ramblock_vfn_hash(const char *idstr, uint64_t vfn, uint32_t crc) "ramblock n
>>   calc_page_dirty_rate(const char *idstr, uint32_t new_crc, uint32_t old_crc) "ramblock name: %s, new crc: %" PRIu32 ", old crc: %" PRIu32
>>   skip_sample_ramblock(const char *idstr, uint64_t ramblock_size) "ramblock name: %s, ramblock size: %" PRIu64
>>   find_page_matched(const char *idstr) "ramblock %s addr or size changed"
>> +
>> +# block.c
>> +init_blk_migration_shared(const char *blk_device_name) "Start migration for %s with shared base image"
>> +init_blk_migration_full(const char *blk_device_name) "Start full migration for %s"
>> +mig_save_device_dirty(int64_t sector) "Error reading sector %" PRId64
>> +flush_blks(const char *action, int submitted, int read_done, int transferred) "%s submitted %d read_done %d transferred %d"
> 
> When using tracing, you usually start with a global pattern,
> then slowly remove events until tracing the particular one
> interesting you. As these all belong to the same subsystem,
> please use "migration_block_" prefix for all.

All migration block file trace function need add "migration_block_"? Such as:
migration_block_init_blk_migration_shared()
migration_block_init_blk_migration_full()
...

> 
>> +migration_block_save(const char *mig_stage, int submitted, int transferred) "Enter save live %s submitted %d transferred %d"
>> +migration_block_save_complete(void) "Block migration completed"
>> +migration_block_save_pending(uint64_t pending) "Enter save live pending  %" PRIu64
> 
> These are good.
> 
>> +
>> +# page_cache.c
>> +cache_init(int64_t max_num_items) "Setting cache buckets to %" PRId64
>> +cache_insert(void) "Error allocating page"
> 
> Please use "migration_block_" prefix here too.

Do you mean using "migration_" prefix? Such as:
migration_cache_init()
migration_cache_insert()
...

> 
> Regards,
> 
> Phil.
> 
> .
Philippe Mathieu-Daudé Oct. 20, 2020, 7:18 a.m. UTC | #3
On 10/20/20 9:07 AM, Bihong Yu wrote:
> 
> 
> On 2020/10/20 14:54, Philippe Mathieu-Daudé wrote:
>> On 10/20/20 8:42 AM, Bihong Yu wrote:
>>> Signed-off-by: Bihong Yu <yubihong@huawei.com>
>>> ---
>>>    migration/block.c      | 36 ++++++++++++++++++------------------
>>>    migration/page_cache.c | 13 +++----------
>>>    migration/trace-events | 13 +++++++++++++
>>>    3 files changed, 34 insertions(+), 28 deletions(-)
>>>
>>> diff --git a/migration/block.c b/migration/block.c
>>> index 273392b..1e76a9f 100644
>>> --- a/migration/block.c
>>> +++ b/migration/block.c
>>> @@ -26,6 +26,7 @@
>>>    #include "qemu-file.h"
>>>    #include "migration/vmstate.h"
>>>    #include "sysemu/block-backend.h"
>>> +#include "trace.h"
>>>      #define BLK_MIG_BLOCK_SIZE           (1 << 20)
>>>    #define BDRV_SECTORS_PER_DIRTY_CHUNK (BLK_MIG_BLOCK_SIZE >> BDRV_SECTOR_BITS)
>>> @@ -434,10 +435,9 @@ static int init_blk_migration(QEMUFile *f)
>>>            block_mig_state.total_sector_sum += sectors;
>>>              if (bmds->shared_base) {
>>> -            DPRINTF("Start migration for %s with shared base image\n",
>>> -                    bdrv_get_device_name(bs));
>>> +            trace_init_blk_migration_shared(bdrv_get_device_name(bs));
>>>            } else {
>>> -            DPRINTF("Start full migration for %s\n", bdrv_get_device_name(bs));
>>> +            trace_init_blk_migration_full(bdrv_get_device_name(bs));
>>>            }
>>>              QSIMPLEQ_INSERT_TAIL(&block_mig_state.bmds_list, bmds, entry);
>>> @@ -592,7 +592,7 @@ static int mig_save_device_dirty(QEMUFile *f, BlkMigDevState *bmds,
>>>        return (bmds->cur_dirty >= bmds->total_sectors);
>>>      error:
>>> -    DPRINTF("Error reading sector %" PRId64 "\n", sector);
>>> +    trace_mig_save_device_dirty(sector);
>>>        g_free(blk->buf);
>>>        g_free(blk);
>>>        return ret;
>>> @@ -628,9 +628,9 @@ static int flush_blks(QEMUFile *f)
>>>        BlkMigBlock *blk;
>>>        int ret = 0;
>>>    -    DPRINTF("%s Enter submitted %d read_done %d transferred %d\n",
>>> -            __func__, block_mig_state.submitted, block_mig_state.read_done,
>>> -            block_mig_state.transferred);
>>> +    trace_flush_blks("Enter", block_mig_state.submitted,
>>> +                     block_mig_state.read_done,
>>> +                     block_mig_state.transferred);
>>>          blk_mig_lock();
>>>        while ((blk = QSIMPLEQ_FIRST(&block_mig_state.blk_list)) != NULL) {
>>> @@ -656,9 +656,9 @@ static int flush_blks(QEMUFile *f)
>>>        }
>>>        blk_mig_unlock();
>>>    -    DPRINTF("%s Exit submitted %d read_done %d transferred %d\n", __func__,
>>> -            block_mig_state.submitted, block_mig_state.read_done,
>>> -            block_mig_state.transferred);
>>> +    trace_flush_blks("Exit", block_mig_state.submitted,
>>> +                     block_mig_state.read_done,
>>> +                     block_mig_state.transferred);
>>>        return ret;
>>>    }
>>>    @@ -727,8 +727,8 @@ static int block_save_setup(QEMUFile *f, void *opaque)
>>>    {
>>>        int ret;
>>>    -    DPRINTF("Enter save live setup submitted %d transferred %d\n",
>>> -            block_mig_state.submitted, block_mig_state.transferred);
>>> +    trace_migration_block_save("setup", block_mig_state.submitted,
>>> +                               block_mig_state.transferred);
>>>          qemu_mutex_lock_iothread();
>>>        ret = init_blk_migration(f);
>>> @@ -759,8 +759,8 @@ static int block_save_iterate(QEMUFile *f, void *opaque)
>>>        int64_t last_ftell = qemu_ftell(f);
>>>        int64_t delta_ftell;
>>>    -    DPRINTF("Enter save live iterate submitted %d transferred %d\n",
>>> -            block_mig_state.submitted, block_mig_state.transferred);
>>> +    trace_migration_block_save("iterate", block_mig_state.submitted,
>>> +                               block_mig_state.transferred);
>>>          ret = flush_blks(f);
>>>        if (ret) {
>>> @@ -825,8 +825,8 @@ static int block_save_complete(QEMUFile *f, void *opaque)
>>>    {
>>>        int ret;
>>>    -    DPRINTF("Enter save live complete submitted %d transferred %d\n",
>>> -            block_mig_state.submitted, block_mig_state.transferred);
>>> +    trace_migration_block_save("complete", block_mig_state.submitted,
>>> +                               block_mig_state.transferred);
>>>          ret = flush_blks(f);
>>>        if (ret) {
>>> @@ -851,7 +851,7 @@ static int block_save_complete(QEMUFile *f, void *opaque)
>>>        /* report completion */
>>>        qemu_put_be64(f, (100 << BDRV_SECTOR_BITS) | BLK_MIG_FLAG_PROGRESS);
>>>    -    DPRINTF("Block migration completed\n");
>>> +    trace_migration_block_save_complete();
>>>          qemu_put_be64(f, BLK_MIG_FLAG_EOS);
>>>    @@ -884,7 +884,7 @@ static void block_save_pending(QEMUFile *f, void *opaque, uint64_t max_size,
>>>            pending = max_size + BLK_MIG_BLOCK_SIZE;
>>>        }
>>>    -    DPRINTF("Enter save live pending  %" PRIu64 "\n", pending);
>>> +    trace_migration_block_save_pending(pending);
>>>        /* We don't do postcopy */
>>>        *res_precopy_only += pending;
>>>    }
>>> diff --git a/migration/page_cache.c b/migration/page_cache.c
>>> index 775582f..d554efa 100644
>>> --- a/migration/page_cache.c
>>> +++ b/migration/page_cache.c
>>> @@ -18,14 +18,7 @@
>>>    #include "qapi/error.h"
>>>    #include "qemu/host-utils.h"
>>>    #include "page_cache.h"
>>> -
>>> -#ifdef DEBUG_CACHE
>>> -#define DPRINTF(fmt, ...) \
>>> -    do { fprintf(stdout, "cache: " fmt, ## __VA_ARGS__); } while (0)
>>> -#else
>>> -#define DPRINTF(fmt, ...) \
>>> -    do { } while (0)
>>> -#endif
>>> +#include "trace.h"
>>>      /* the page in cache will not be replaced in two cycles */
>>>    #define CACHED_PAGE_LIFETIME 2
>>> @@ -75,7 +68,7 @@ PageCache *cache_init(int64_t new_size, size_t page_size, Error **errp)
>>>        cache->num_items = 0;
>>>        cache->max_num_items = num_pages;
>>>    -    DPRINTF("Setting cache buckets to %" PRId64 "\n", cache->max_num_items);
>>> +    trace_cache_init(cache->max_num_items);
>>>          /* We prefer not to abort if there is no memory */
>>>        cache->page_cache = g_try_malloc((cache->max_num_items) *
>>> @@ -169,7 +162,7 @@ int cache_insert(PageCache *cache, uint64_t addr, const uint8_t *pdata,
>>>        if (!it->it_data) {
>>>            it->it_data = g_try_malloc(cache->page_size);
>>>            if (!it->it_data) {
>>> -            DPRINTF("Error allocating page\n");
>>> +            trace_cache_insert();
>>>                return -1;
>>>            }
>>>            cache->num_items++;
>>> diff --git a/migration/trace-events b/migration/trace-events
>>> index 338f38b..094dbe4 100644
>>> --- a/migration/trace-events
>>> +++ b/migration/trace-events
>>> @@ -325,3 +325,16 @@ get_ramblock_vfn_hash(const char *idstr, uint64_t vfn, uint32_t crc) "ramblock n
>>>    calc_page_dirty_rate(const char *idstr, uint32_t new_crc, uint32_t old_crc) "ramblock name: %s, new crc: %" PRIu32 ", old crc: %" PRIu32
>>>    skip_sample_ramblock(const char *idstr, uint64_t ramblock_size) "ramblock name: %s, ramblock size: %" PRIu64
>>>    find_page_matched(const char *idstr) "ramblock %s addr or size changed"
>>> +
>>> +# block.c
>>> +init_blk_migration_shared(const char *blk_device_name) "Start migration for %s with shared base image"
>>> +init_blk_migration_full(const char *blk_device_name) "Start full migration for %s"
>>> +mig_save_device_dirty(int64_t sector) "Error reading sector %" PRId64
>>> +flush_blks(const char *action, int submitted, int read_done, int transferred) "%s submitted %d read_done %d transferred %d"
>>
>> When using tracing, you usually start with a global pattern,
>> then slowly remove events until tracing the particular one
>> interesting you. As these all belong to the same subsystem,
>> please use "migration_block_" prefix for all.
> 
> All migration block file trace function need add "migration_block_"? Such as:
> migration_block_init_blk_migration_shared()

   -> migration_block_init_shared

> migration_block_init_blk_migration_full()

   -> migration_block_init_full

> ...
> 
>>
>>> +migration_block_save(const char *mig_stage, int submitted, int transferred) "Enter save live %s submitted %d transferred %d"
>>> +migration_block_save_complete(void) "Block migration completed"
>>> +migration_block_save_pending(uint64_t pending) "Enter save live pending  %" PRIu64
>>
>> These are good.
>>
>>> +
>>> +# page_cache.c
>>> +cache_init(int64_t max_num_items) "Setting cache buckets to %" PRId64
>>> +cache_insert(void) "Error allocating page"
>>
>> Please use "migration_block_" prefix here too.
> 
> Do you mean using "migration_" prefix? Such as:
> migration_cache_init()
> migration_cache_insert()
> ...

Yes ;) Or even:

  - migration_pagecache_init
  - migration_pagecache_insert

> 
>>
>> Regards,
>>
>> Phil.
>>
>> .
>
Bihong Yu Oct. 20, 2020, 7:21 a.m. UTC | #4
OK, thank you for your help.

On 2020/10/20 15:18, Philippe Mathieu-Daudé wrote:
> On 10/20/20 9:07 AM, Bihong Yu wrote:

>>

>>

>> On 2020/10/20 14:54, Philippe Mathieu-Daudé wrote:

>>> On 10/20/20 8:42 AM, Bihong Yu wrote:

>>>> Signed-off-by: Bihong Yu <yubihong@huawei.com>

>>>> ---

>>>>    migration/block.c      | 36 ++++++++++++++++++------------------

>>>>    migration/page_cache.c | 13 +++----------

>>>>    migration/trace-events | 13 +++++++++++++

>>>>    3 files changed, 34 insertions(+), 28 deletions(-)

>>>>

>>>> diff --git a/migration/block.c b/migration/block.c

>>>> index 273392b..1e76a9f 100644

>>>> --- a/migration/block.c

>>>> +++ b/migration/block.c

>>>> @@ -26,6 +26,7 @@

>>>>    #include "qemu-file.h"

>>>>    #include "migration/vmstate.h"

>>>>    #include "sysemu/block-backend.h"

>>>> +#include "trace.h"

>>>>      #define BLK_MIG_BLOCK_SIZE           (1 << 20)

>>>>    #define BDRV_SECTORS_PER_DIRTY_CHUNK (BLK_MIG_BLOCK_SIZE >> BDRV_SECTOR_BITS)

>>>> @@ -434,10 +435,9 @@ static int init_blk_migration(QEMUFile *f)

>>>>            block_mig_state.total_sector_sum += sectors;

>>>>              if (bmds->shared_base) {

>>>> -            DPRINTF("Start migration for %s with shared base image\n",

>>>> -                    bdrv_get_device_name(bs));

>>>> +            trace_init_blk_migration_shared(bdrv_get_device_name(bs));

>>>>            } else {

>>>> -            DPRINTF("Start full migration for %s\n", bdrv_get_device_name(bs));

>>>> +            trace_init_blk_migration_full(bdrv_get_device_name(bs));

>>>>            }

>>>>              QSIMPLEQ_INSERT_TAIL(&block_mig_state.bmds_list, bmds, entry);

>>>> @@ -592,7 +592,7 @@ static int mig_save_device_dirty(QEMUFile *f, BlkMigDevState *bmds,

>>>>        return (bmds->cur_dirty >= bmds->total_sectors);

>>>>      error:

>>>> -    DPRINTF("Error reading sector %" PRId64 "\n", sector);

>>>> +    trace_mig_save_device_dirty(sector);

>>>>        g_free(blk->buf);

>>>>        g_free(blk);

>>>>        return ret;

>>>> @@ -628,9 +628,9 @@ static int flush_blks(QEMUFile *f)

>>>>        BlkMigBlock *blk;

>>>>        int ret = 0;

>>>>    -    DPRINTF("%s Enter submitted %d read_done %d transferred %d\n",

>>>> -            __func__, block_mig_state.submitted, block_mig_state.read_done,

>>>> -            block_mig_state.transferred);

>>>> +    trace_flush_blks("Enter", block_mig_state.submitted,

>>>> +                     block_mig_state.read_done,

>>>> +                     block_mig_state.transferred);

>>>>          blk_mig_lock();

>>>>        while ((blk = QSIMPLEQ_FIRST(&block_mig_state.blk_list)) != NULL) {

>>>> @@ -656,9 +656,9 @@ static int flush_blks(QEMUFile *f)

>>>>        }

>>>>        blk_mig_unlock();

>>>>    -    DPRINTF("%s Exit submitted %d read_done %d transferred %d\n", __func__,

>>>> -            block_mig_state.submitted, block_mig_state.read_done,

>>>> -            block_mig_state.transferred);

>>>> +    trace_flush_blks("Exit", block_mig_state.submitted,

>>>> +                     block_mig_state.read_done,

>>>> +                     block_mig_state.transferred);

>>>>        return ret;

>>>>    }

>>>>    @@ -727,8 +727,8 @@ static int block_save_setup(QEMUFile *f, void *opaque)

>>>>    {

>>>>        int ret;

>>>>    -    DPRINTF("Enter save live setup submitted %d transferred %d\n",

>>>> -            block_mig_state.submitted, block_mig_state.transferred);

>>>> +    trace_migration_block_save("setup", block_mig_state.submitted,

>>>> +                               block_mig_state.transferred);

>>>>          qemu_mutex_lock_iothread();

>>>>        ret = init_blk_migration(f);

>>>> @@ -759,8 +759,8 @@ static int block_save_iterate(QEMUFile *f, void *opaque)

>>>>        int64_t last_ftell = qemu_ftell(f);

>>>>        int64_t delta_ftell;

>>>>    -    DPRINTF("Enter save live iterate submitted %d transferred %d\n",

>>>> -            block_mig_state.submitted, block_mig_state.transferred);

>>>> +    trace_migration_block_save("iterate", block_mig_state.submitted,

>>>> +                               block_mig_state.transferred);

>>>>          ret = flush_blks(f);

>>>>        if (ret) {

>>>> @@ -825,8 +825,8 @@ static int block_save_complete(QEMUFile *f, void *opaque)

>>>>    {

>>>>        int ret;

>>>>    -    DPRINTF("Enter save live complete submitted %d transferred %d\n",

>>>> -            block_mig_state.submitted, block_mig_state.transferred);

>>>> +    trace_migration_block_save("complete", block_mig_state.submitted,

>>>> +                               block_mig_state.transferred);

>>>>          ret = flush_blks(f);

>>>>        if (ret) {

>>>> @@ -851,7 +851,7 @@ static int block_save_complete(QEMUFile *f, void *opaque)

>>>>        /* report completion */

>>>>        qemu_put_be64(f, (100 << BDRV_SECTOR_BITS) | BLK_MIG_FLAG_PROGRESS);

>>>>    -    DPRINTF("Block migration completed\n");

>>>> +    trace_migration_block_save_complete();

>>>>          qemu_put_be64(f, BLK_MIG_FLAG_EOS);

>>>>    @@ -884,7 +884,7 @@ static void block_save_pending(QEMUFile *f, void *opaque, uint64_t max_size,

>>>>            pending = max_size + BLK_MIG_BLOCK_SIZE;

>>>>        }

>>>>    -    DPRINTF("Enter save live pending  %" PRIu64 "\n", pending);

>>>> +    trace_migration_block_save_pending(pending);

>>>>        /* We don't do postcopy */

>>>>        *res_precopy_only += pending;

>>>>    }

>>>> diff --git a/migration/page_cache.c b/migration/page_cache.c

>>>> index 775582f..d554efa 100644

>>>> --- a/migration/page_cache.c

>>>> +++ b/migration/page_cache.c

>>>> @@ -18,14 +18,7 @@

>>>>    #include "qapi/error.h"

>>>>    #include "qemu/host-utils.h"

>>>>    #include "page_cache.h"

>>>> -

>>>> -#ifdef DEBUG_CACHE

>>>> -#define DPRINTF(fmt, ...) \

>>>> -    do { fprintf(stdout, "cache: " fmt, ## __VA_ARGS__); } while (0)

>>>> -#else

>>>> -#define DPRINTF(fmt, ...) \

>>>> -    do { } while (0)

>>>> -#endif

>>>> +#include "trace.h"

>>>>      /* the page in cache will not be replaced in two cycles */

>>>>    #define CACHED_PAGE_LIFETIME 2

>>>> @@ -75,7 +68,7 @@ PageCache *cache_init(int64_t new_size, size_t page_size, Error **errp)

>>>>        cache->num_items = 0;

>>>>        cache->max_num_items = num_pages;

>>>>    -    DPRINTF("Setting cache buckets to %" PRId64 "\n", cache->max_num_items);

>>>> +    trace_cache_init(cache->max_num_items);

>>>>          /* We prefer not to abort if there is no memory */

>>>>        cache->page_cache = g_try_malloc((cache->max_num_items) *

>>>> @@ -169,7 +162,7 @@ int cache_insert(PageCache *cache, uint64_t addr, const uint8_t *pdata,

>>>>        if (!it->it_data) {

>>>>            it->it_data = g_try_malloc(cache->page_size);

>>>>            if (!it->it_data) {

>>>> -            DPRINTF("Error allocating page\n");

>>>> +            trace_cache_insert();

>>>>                return -1;

>>>>            }

>>>>            cache->num_items++;

>>>> diff --git a/migration/trace-events b/migration/trace-events

>>>> index 338f38b..094dbe4 100644

>>>> --- a/migration/trace-events

>>>> +++ b/migration/trace-events

>>>> @@ -325,3 +325,16 @@ get_ramblock_vfn_hash(const char *idstr, uint64_t vfn, uint32_t crc) "ramblock n

>>>>    calc_page_dirty_rate(const char *idstr, uint32_t new_crc, uint32_t old_crc) "ramblock name: %s, new crc: %" PRIu32 ", old crc: %" PRIu32

>>>>    skip_sample_ramblock(const char *idstr, uint64_t ramblock_size) "ramblock name: %s, ramblock size: %" PRIu64

>>>>    find_page_matched(const char *idstr) "ramblock %s addr or size changed"

>>>> +

>>>> +# block.c

>>>> +init_blk_migration_shared(const char *blk_device_name) "Start migration for %s with shared base image"

>>>> +init_blk_migration_full(const char *blk_device_name) "Start full migration for %s"

>>>> +mig_save_device_dirty(int64_t sector) "Error reading sector %" PRId64

>>>> +flush_blks(const char *action, int submitted, int read_done, int transferred) "%s submitted %d read_done %d transferred %d"

>>>

>>> When using tracing, you usually start with a global pattern,

>>> then slowly remove events until tracing the particular one

>>> interesting you. As these all belong to the same subsystem,

>>> please use "migration_block_" prefix for all.

>>

>> All migration block file trace function need add "migration_block_"? Such as:

>> migration_block_init_blk_migration_shared()

> 

>   -> migration_block_init_shared

> 

>> migration_block_init_blk_migration_full()

> 

>   -> migration_block_init_full

> 

>> ...

>>

>>>

>>>> +migration_block_save(const char *mig_stage, int submitted, int transferred) "Enter save live %s submitted %d transferred %d"

>>>> +migration_block_save_complete(void) "Block migration completed"

>>>> +migration_block_save_pending(uint64_t pending) "Enter save live pending  %" PRIu64

>>>

>>> These are good.

>>>

>>>> +

>>>> +# page_cache.c

>>>> +cache_init(int64_t max_num_items) "Setting cache buckets to %" PRId64

>>>> +cache_insert(void) "Error allocating page"

>>>

>>> Please use "migration_block_" prefix here too.

>>

>> Do you mean using "migration_" prefix? Such as:

>> migration_cache_init()

>> migration_cache_insert()

>> ...

> 

> Yes ;) Or even:

> 

>  - migration_pagecache_init

>  - migration_pagecache_insert

> 

>>

>>>

>>> Regards,

>>>

>>> Phil.

>>>

>>> .

>>

> 

> .
diff mbox series

Patch

diff --git a/migration/block.c b/migration/block.c
index 273392b..1e76a9f 100644
--- a/migration/block.c
+++ b/migration/block.c
@@ -26,6 +26,7 @@ 
 #include "qemu-file.h"
 #include "migration/vmstate.h"
 #include "sysemu/block-backend.h"
+#include "trace.h"
 
 #define BLK_MIG_BLOCK_SIZE           (1 << 20)
 #define BDRV_SECTORS_PER_DIRTY_CHUNK (BLK_MIG_BLOCK_SIZE >> BDRV_SECTOR_BITS)
@@ -434,10 +435,9 @@  static int init_blk_migration(QEMUFile *f)
         block_mig_state.total_sector_sum += sectors;
 
         if (bmds->shared_base) {
-            DPRINTF("Start migration for %s with shared base image\n",
-                    bdrv_get_device_name(bs));
+            trace_init_blk_migration_shared(bdrv_get_device_name(bs));
         } else {
-            DPRINTF("Start full migration for %s\n", bdrv_get_device_name(bs));
+            trace_init_blk_migration_full(bdrv_get_device_name(bs));
         }
 
         QSIMPLEQ_INSERT_TAIL(&block_mig_state.bmds_list, bmds, entry);
@@ -592,7 +592,7 @@  static int mig_save_device_dirty(QEMUFile *f, BlkMigDevState *bmds,
     return (bmds->cur_dirty >= bmds->total_sectors);
 
 error:
-    DPRINTF("Error reading sector %" PRId64 "\n", sector);
+    trace_mig_save_device_dirty(sector);
     g_free(blk->buf);
     g_free(blk);
     return ret;
@@ -628,9 +628,9 @@  static int flush_blks(QEMUFile *f)
     BlkMigBlock *blk;
     int ret = 0;
 
-    DPRINTF("%s Enter submitted %d read_done %d transferred %d\n",
-            __func__, block_mig_state.submitted, block_mig_state.read_done,
-            block_mig_state.transferred);
+    trace_flush_blks("Enter", block_mig_state.submitted,
+                     block_mig_state.read_done,
+                     block_mig_state.transferred);
 
     blk_mig_lock();
     while ((blk = QSIMPLEQ_FIRST(&block_mig_state.blk_list)) != NULL) {
@@ -656,9 +656,9 @@  static int flush_blks(QEMUFile *f)
     }
     blk_mig_unlock();
 
-    DPRINTF("%s Exit submitted %d read_done %d transferred %d\n", __func__,
-            block_mig_state.submitted, block_mig_state.read_done,
-            block_mig_state.transferred);
+    trace_flush_blks("Exit", block_mig_state.submitted,
+                     block_mig_state.read_done,
+                     block_mig_state.transferred);
     return ret;
 }
 
@@ -727,8 +727,8 @@  static int block_save_setup(QEMUFile *f, void *opaque)
 {
     int ret;
 
-    DPRINTF("Enter save live setup submitted %d transferred %d\n",
-            block_mig_state.submitted, block_mig_state.transferred);
+    trace_migration_block_save("setup", block_mig_state.submitted,
+                               block_mig_state.transferred);
 
     qemu_mutex_lock_iothread();
     ret = init_blk_migration(f);
@@ -759,8 +759,8 @@  static int block_save_iterate(QEMUFile *f, void *opaque)
     int64_t last_ftell = qemu_ftell(f);
     int64_t delta_ftell;
 
-    DPRINTF("Enter save live iterate submitted %d transferred %d\n",
-            block_mig_state.submitted, block_mig_state.transferred);
+    trace_migration_block_save("iterate", block_mig_state.submitted,
+                               block_mig_state.transferred);
 
     ret = flush_blks(f);
     if (ret) {
@@ -825,8 +825,8 @@  static int block_save_complete(QEMUFile *f, void *opaque)
 {
     int ret;
 
-    DPRINTF("Enter save live complete submitted %d transferred %d\n",
-            block_mig_state.submitted, block_mig_state.transferred);
+    trace_migration_block_save("complete", block_mig_state.submitted,
+                               block_mig_state.transferred);
 
     ret = flush_blks(f);
     if (ret) {
@@ -851,7 +851,7 @@  static int block_save_complete(QEMUFile *f, void *opaque)
     /* report completion */
     qemu_put_be64(f, (100 << BDRV_SECTOR_BITS) | BLK_MIG_FLAG_PROGRESS);
 
-    DPRINTF("Block migration completed\n");
+    trace_migration_block_save_complete();
 
     qemu_put_be64(f, BLK_MIG_FLAG_EOS);
 
@@ -884,7 +884,7 @@  static void block_save_pending(QEMUFile *f, void *opaque, uint64_t max_size,
         pending = max_size + BLK_MIG_BLOCK_SIZE;
     }
 
-    DPRINTF("Enter save live pending  %" PRIu64 "\n", pending);
+    trace_migration_block_save_pending(pending);
     /* We don't do postcopy */
     *res_precopy_only += pending;
 }
diff --git a/migration/page_cache.c b/migration/page_cache.c
index 775582f..d554efa 100644
--- a/migration/page_cache.c
+++ b/migration/page_cache.c
@@ -18,14 +18,7 @@ 
 #include "qapi/error.h"
 #include "qemu/host-utils.h"
 #include "page_cache.h"
-
-#ifdef DEBUG_CACHE
-#define DPRINTF(fmt, ...) \
-    do { fprintf(stdout, "cache: " fmt, ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...) \
-    do { } while (0)
-#endif
+#include "trace.h"
 
 /* the page in cache will not be replaced in two cycles */
 #define CACHED_PAGE_LIFETIME 2
@@ -75,7 +68,7 @@  PageCache *cache_init(int64_t new_size, size_t page_size, Error **errp)
     cache->num_items = 0;
     cache->max_num_items = num_pages;
 
-    DPRINTF("Setting cache buckets to %" PRId64 "\n", cache->max_num_items);
+    trace_cache_init(cache->max_num_items);
 
     /* We prefer not to abort if there is no memory */
     cache->page_cache = g_try_malloc((cache->max_num_items) *
@@ -169,7 +162,7 @@  int cache_insert(PageCache *cache, uint64_t addr, const uint8_t *pdata,
     if (!it->it_data) {
         it->it_data = g_try_malloc(cache->page_size);
         if (!it->it_data) {
-            DPRINTF("Error allocating page\n");
+            trace_cache_insert();
             return -1;
         }
         cache->num_items++;
diff --git a/migration/trace-events b/migration/trace-events
index 338f38b..094dbe4 100644
--- a/migration/trace-events
+++ b/migration/trace-events
@@ -325,3 +325,16 @@  get_ramblock_vfn_hash(const char *idstr, uint64_t vfn, uint32_t crc) "ramblock n
 calc_page_dirty_rate(const char *idstr, uint32_t new_crc, uint32_t old_crc) "ramblock name: %s, new crc: %" PRIu32 ", old crc: %" PRIu32
 skip_sample_ramblock(const char *idstr, uint64_t ramblock_size) "ramblock name: %s, ramblock size: %" PRIu64
 find_page_matched(const char *idstr) "ramblock %s addr or size changed"
+
+# block.c
+init_blk_migration_shared(const char *blk_device_name) "Start migration for %s with shared base image"
+init_blk_migration_full(const char *blk_device_name) "Start full migration for %s"
+mig_save_device_dirty(int64_t sector) "Error reading sector %" PRId64
+flush_blks(const char *action, int submitted, int read_done, int transferred) "%s submitted %d read_done %d transferred %d"
+migration_block_save(const char *mig_stage, int submitted, int transferred) "Enter save live %s submitted %d transferred %d"
+migration_block_save_complete(void) "Block migration completed"
+migration_block_save_pending(uint64_t pending) "Enter save live pending  %" PRIu64
+
+# page_cache.c
+cache_init(int64_t max_num_items) "Setting cache buckets to %" PRId64
+cache_insert(void) "Error allocating page"