[CRIU] [PATCH v2] Added option to display dump/restore stats

[Kir Kolyshkin]

On 10/10/2016 08:26 AM, Adrian Reber wrote:
> From: Adrian Reber <areber at redhat.com>
>
> Currently criu writes dump/restore statistics to a file. This patch adds
> the option '--display-stats' which additionally displays the same
> information on the console:

Adrian,

Please send a patch for the man page (Documentation/criu.txt) as well.

>
>   # criu dump --display-stats -D /tmp/cp -t <PID>
>   Displaying dump stats:
>   Freezing time: 133 us
>   Frozen time: 135173 us
>   Memory dump time: 114760 us
>   Memory write time: 85107 us
>   IRMAP resolve time: 0 us
>   Memory pages scanned: 2099 (0x833)
>   Memory pages skipped from parent: 0 (0x0)
>   Memory pages written: 1052 (0x41c)
>   Zero memory pages: 0 (0x0)
>   Lazy memory pages: 0 (0x0)
>
>   # criu restore --display-stats -D /tmp/cp
>   Displaying restore stats:
>   Pages compared: 0 (0x0)
>   Pages skipped COW: 0 (0x0)
>   Pages restored: 51227 (0xc81b)
>   Restore time: 57428 us
>   Forking time: 51473 us
>
> v2:
>   - fix compile failure on 32bit ARM
>
> Signed-off-by: Adrian Reber <areber at redhat.com>
> ---
>   criu/crtools.c            |  5 +++++
>   criu/include/cr_options.h |  1 +
>   criu/stats.c              | 40 ++++++++++++++++++++++++++++++++++++++++
>   3 files changed, 46 insertions(+)
>
> diff --git a/criu/crtools.c b/criu/crtools.c
> index 0e853ee..8b5ec5d 100644
> --- a/criu/crtools.c
> +++ b/criu/crtools.c
> @@ -279,6 +279,7 @@ int main(int argc, char *argv[], char *envp[])
>   		{ "cgroup-dump-controller",	required_argument,	0, 1082	},
>   		{ SK_INFLIGHT_PARAM,		no_argument,		0, 1083	},
>   		{ "deprecated",			no_argument,		0, 1084 },
> +		{ "display-stats",		no_argument,		0, 1086 },
>   		{ },
>   	};
>   
> @@ -594,6 +595,9 @@ int main(int argc, char *argv[], char *envp[])
>   			pr_msg("Turn deprecated stuff ON\n");
>   			opts.deprecated_ok = true;
>   			break;
> +		case 1086:
> +			opts.display_stats = true;
> +			break;
>   		case 'V':
>   			pr_msg("Version: %s\n", CRIU_VERSION);
>   			if (strcmp(CRIU_GITID, "0"))
> @@ -919,6 +923,7 @@ usage:
>   "                          -v2|-vv   - also warnings (default level)\n"
>   "                          -v3|-vvv  - also information messages and timestamps\n"
>   "                          -v4|-vvvv - lots of debug\n"
> +"  --display-stats       print out dump/restore stats\n"
>   "\n"
>   "* Memory dumping options:\n"
>   "  --track-mem           turn on memory changes tracker in kernel\n"
> diff --git a/criu/include/cr_options.h b/criu/include/cr_options.h
> index 8a9427b..521a896 100644
> --- a/criu/include/cr_options.h
> +++ b/criu/include/cr_options.h
> @@ -114,6 +114,7 @@ struct cr_options {
>   	 * to turn one ON while the code is in.
>   	 */
>   	bool			deprecated_ok;
> +	bool			display_stats;
>   };
>   
>   extern struct cr_options opts;
> diff --git a/criu/stats.c b/criu/stats.c
> index a575e77..661c2e0 100644
> --- a/criu/stats.c
> +++ b/criu/stats.c
> @@ -2,6 +2,7 @@
>   #include <fcntl.h>
>   #include <sys/time.h>
>   #include "asm/atomic.h"
> +#include "cr_options.h"
>   #include "rst-malloc.h"
>   #include "protobuf.h"
>   #include "stats.h"
> @@ -100,6 +101,42 @@ static void encode_time(int t, u_int32_t *to)
>   	*to = tm->total.tv_sec * USEC_PER_SEC + tm->total.tv_usec;
>   }
>   
> +static void display_stats(int what, StatsEntry *stats)
> +{
> +	if (what == DUMP_STATS) {
> +		pr_msg("Displaying dump stats:\n");
> +		pr_msg("Freezing time: %d us\n", stats->dump->freezing_time);
> +		pr_msg("Frozen time: %d us\n", stats->dump->frozen_time);
> +		pr_msg("Memory dump time: %d us\n", stats->dump->memdump_time);
> +		pr_msg("Memory write time: %d us\n", stats->dump->memwrite_time);
> +		if (stats->dump->has_irmap_resolve)
> +			pr_msg("IRMAP resolve time: %d us\n", stats->dump->irmap_resolve);
> +		pr_msg("Memory pages scanned: %" PRIu64 " (0x%" PRIx64 ")\n", stats->dump->pages_scanned,
> +				stats->dump->pages_scanned);
> +		pr_msg("Memory pages skipped from parent: %" PRIu64 " (0x%" PRIx64 ")\n",
> +				stats->dump->pages_skipped_parent,
> +				stats->dump->pages_skipped_parent);
> +		pr_msg("Memory pages written: %" PRIu64 " (0x%" PRIx64 ")\n", stats->dump->pages_written,
> +				stats->dump->pages_written);
> +		pr_msg("Zero memory pages: %" PRIu64 " (0x%" PRIx64 ")\n", stats->dump->pages_zero,
> +				stats->dump->pages_zero);
> +		pr_msg("Lazy memory pages: %" PRIu64 " (0x%" PRIx64 ")\n", stats->dump->pages_lazy,
> +				stats->dump->pages_lazy);
> +	} else if (what == RESTORE_STATS) {
> +		pr_msg("Displaying restore stats:\n");
> +		pr_msg("Pages compared: %" PRIu64 " (0x%" PRIx64 ")\n", stats->restore->pages_compared,
> +				stats->restore->pages_compared);
> +		pr_msg("Pages skipped COW: %" PRIu64 " (0x%" PRIx64 ")\n", stats->restore->pages_skipped_cow,
> +				stats->restore->pages_skipped_cow);
> +		if (stats->restore->has_pages_restored)
> +			pr_msg("Pages restored: %" PRIu64 " (0x%" PRIx64 ")\n", stats->restore->pages_restored,
> +					stats->restore->pages_restored);
> +		pr_msg("Restore time: %d us\n", stats->restore->restore_time);
> +		pr_msg("Forking time: %d us\n", stats->restore->forking_time);
> +	} else
> +		return;
> +}
> +
>   void write_stats(int what)
>   {
>   	StatsEntry stats = STATS_ENTRY__INIT;
> @@ -146,6 +183,9 @@ void write_stats(int what)
>   		pb_write_one(img, &stats, PB_STATS);
>   		close_image(img);
>   	}
> +
> +	if (opts.display_stats)
> +		display_stats(what, &stats);
>   }
>   
>   int init_stats(int what)