[RFC PATCH] pack-objects: write objects packed to trace2

[RFC PATCH] pack-objects: write objects packed to trace2

[Jonathan Tan]

This is useful when investigating performance of pushes, and other times
when no progress information is written (because the pack is written to
stdout).

Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
---
We're trying to improve push performance, and it would be nice to be
able to observe the number of objects sent over each push, both to
correlate it with time taken (which is already traced) and to notice
situations when significantly more objects are being sent than needed.

Sending this as an RFC because this patch works but is somewhat ad-hoc -
perhaps someone else has a more comprehensive solution.
---
 builtin/pack-objects.c | 1 +
 1 file changed, 1 insertion(+)

diff --git a/builtin/pack-objects.c b/builtin/pack-objects.c
index a154fc29f6..ac464d7d07 100644
--- a/builtin/pack-objects.c
+++ b/builtin/pack-objects.c
@@ -964,6 +964,7 @@ static void write_pack_file(void)
 	if (written != nr_result)
 		die(_("wrote %"PRIu32" objects while expecting %"PRIu32),
 		    written, nr_result);
+	trace2_printf("packed %d objects", nr_result);
 }
 
 static int no_try_delta(const char *path)
-- 
2.21.0.392.gf8f6787159e-goog

Re: [RFC PATCH] pack-objects: write objects packed to trace2

[Junio C Hamano]

Jonathan Tan <jonathantanmy@google.com> writes:

> This is useful when investigating performance of pushes, and other times
> when no progress information is written (because the pack is written to
> stdout).
>
> Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
> ---
> We're trying to improve push performance, and it would be nice to be
> able to observe the number of objects sent over each push, both to
> correlate it with time taken (which is already traced) and to notice
> situations when significantly more objects are being sent than needed.

Thanks---I find it a laudable goal, too.

Re: [RFC PATCH] pack-objects: write objects packed to trace2

[Duy Nguyen]

On Wed, Apr 10, 2019 at 4:45 AM Jonathan Tan <jonathantanmy@google.com> wrote:
>
> This is useful when investigating performance of pushes, and other times
> when no progress information is written (because the pack is written to
> stdout).
>
> Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
> ---
> We're trying to improve push performance, and it would be nice to be
> able to observe the number of objects sent over each push, both to
> correlate it with time taken (which is already traced) and to notice
> situations when significantly more objects are being sent than needed.
>
> Sending this as an RFC because this patch works but is somewhat ad-hoc -
> perhaps someone else has a more comprehensive solution.
> ---
>  builtin/pack-objects.c | 1 +
>  1 file changed, 1 insertion(+)
>
> diff --git a/builtin/pack-objects.c b/builtin/pack-objects.c
> index a154fc29f6..ac464d7d07 100644
> --- a/builtin/pack-objects.c
> +++ b/builtin/pack-objects.c
> @@ -964,6 +964,7 @@ static void write_pack_file(void)
>         if (written != nr_result)
>                 die(_("wrote %"PRIu32" objects while expecting %"PRIu32),
>                     written, nr_result);
> +       trace2_printf("packed %d objects", nr_result);

The die() line right above uses %PRIu32 instead of %d

>  }
>
>  static int no_try_delta(const char *path)
> --
> 2.21.0.392.gf8f6787159e-goog
>


-- 
Duy

Re: [RFC PATCH] pack-objects: write objects packed to trace2

[Jeff Hostetler]

On 4/9/2019 5:44 PM, Jonathan Tan wrote:
> This is useful when investigating performance of pushes, and other times
> when no progress information is written (because the pack is written to
> stdout).
> 
> Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
> ---
> We're trying to improve push performance, and it would be nice to be
> able to observe the number of objects sent over each push, both to
> correlate it with time taken (which is already traced) and to notice
> situations when significantly more objects are being sent than needed.
> 
> Sending this as an RFC because this patch works but is somewhat ad-hoc -
> perhaps someone else has a more comprehensive solution.
> ---
>   builtin/pack-objects.c | 1 +
>   1 file changed, 1 insertion(+)
> 
> diff --git a/builtin/pack-objects.c b/builtin/pack-objects.c
> index a154fc29f6..ac464d7d07 100644
> --- a/builtin/pack-objects.c
> +++ b/builtin/pack-objects.c
> @@ -964,6 +964,7 @@ static void write_pack_file(void)
>   	if (written != nr_result)
>   		die(_("wrote %"PRIu32" objects while expecting %"PRIu32),
>   		    written, nr_result);
> +	trace2_printf("packed %d objects", nr_result);

For a simple field like this, you might want to use:

	trace2_data_intmax("pack-objects", the_repository,
			   "write_pack_file/wrote", nr_result);

This will give your message visibility in both the perf and event
targets.  The latter makes it easier for post-processing.

jeff

[PATCH v2] pack-objects: write objects packed to trace2

[Jonathan Tan]

This is useful when investigating performance of pushes, and other times
when no progress information is written (because the pack is written to
stdout).

Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
---
Thanks, Duy and Jeff for your comments. I've switched to Jeff's
suggestion (trace2_data_intmax), which also sidesteps Duy's concern
about PRIu32 vs %d.

As far as I can tell, with this change, the Git invocation needing to be
traced must be run with GIT_TR2_EVENT instead of GIT_TR2, but that's
fine.
---
 builtin/pack-objects.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/builtin/pack-objects.c b/builtin/pack-objects.c
index a154fc29f6..3326aeb497 100644
--- a/builtin/pack-objects.c
+++ b/builtin/pack-objects.c
@@ -964,6 +964,8 @@ static void write_pack_file(void)
 	if (written != nr_result)
 		die(_("wrote %"PRIu32" objects while expecting %"PRIu32),
 		    written, nr_result);
+	trace2_data_intmax("pack-objects", the_repository,
+			   "write_pack_file/wrote", nr_result);
 }
 
 static int no_try_delta(const char *path)
-- 
2.21.0.392.gf8f6787159e-goog