[PATCH 0/3] trace: Fix flyrecord alignment issue

[PATCH 0/3] trace: Fix flyrecord alignment issue

[Michal Simek]

Hi,

sandbox is getting bigger and bigger and I have reached the case that
adding some more functions ends up in CI loop failure. After some
investigation I found that flyrecord header have incorrect information
about data offset which is caused by incorrect alignment calculation.
That's why this series is fixing alignment calculation.
I have done it via 3 patches where the first two are just preparing code
for actual fixup.

Thanks,
Michal


Michal Simek (3):
  trace: Use 64bit variable for start and len
  trace: Move trace_clocks description above record offset calculation
  trace: Fix alignment logic in flyrecord header

 tools/proftool.c | 39 ++++++++++++++++++++++++++++++++++-----
 1 file changed, 34 insertions(+), 5 deletions(-)

-- 
2.36.1

[PATCH 1/3] trace: Use 64bit variable for start and len

[Michal Simek]

tputq() requires variables to have 64bit width that's why make them 64bit
to clean alignment requirement.

Signed-off-by: Michal Simek <michal.simek@amd.com>
---

 tools/proftool.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/tools/proftool.c b/tools/proftool.c
index 101bcb63334e..869a2a32c510 100644
--- a/tools/proftool.c
+++ b/tools/proftool.c
@@ -1493,7 +1493,8 @@ static int write_pages(struct twriter *tw, enum out_format_t out_format,
 static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
 			   int *missing_countp, int *skip_countp)
 {
-	int start, ret, len;
+	unsigned long long start, len;
+	int ret;
 	FILE *fout = tw->fout;
 	char str[200];
 
-- 
2.36.1

Re: [PATCH 1/3] trace: Use 64bit variable for start and len

[Simon Glass]

Hi Michal,

On Mon, 11 Sept 2023 at 06:32, Michal Simek <michal.simek@amd.com> wrote:
>
> tputq() requires variables to have 64bit width that's why make them 64bit
> to clean alignment requirement.
>
> Signed-off-by: Michal Simek <michal.simek@amd.com>
> ---
>
>  tools/proftool.c | 3 ++-
>  1 file changed, 2 insertions(+), 1 deletion(-)

Reviewed-by: Simon Glass <sjg@chromium.org>

I would have thought that 'unsigned long' is enough on a 64-bit
machines? Are you running on 32-bit?

>
> diff --git a/tools/proftool.c b/tools/proftool.c
> index 101bcb63334e..869a2a32c510 100644
> --- a/tools/proftool.c
> +++ b/tools/proftool.c
> @@ -1493,7 +1493,8 @@ static int write_pages(struct twriter *tw, enum out_format_t out_format,
>  static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
>                            int *missing_countp, int *skip_countp)
>  {
> -       int start, ret, len;
> +       unsigned long long start, len;
> +       int ret;
>         FILE *fout = tw->fout;
>         char str[200];
>
> --
> 2.36.1
>

Regards,
Simon

Re: [PATCH 1/3] trace: Use 64bit variable for start and len

[Michal Simek]

On 9/12/23 21:26, Simon Glass wrote:
> Hi Michal,
> 
> On Mon, 11 Sept 2023 at 06:32, Michal Simek <michal.simek@amd.com> wrote:
>>
>> tputq() requires variables to have 64bit width that's why make them 64bit
>> to clean alignment requirement.
>>
>> Signed-off-by: Michal Simek <michal.simek@amd.com>
>> ---
>>
>>   tools/proftool.c | 3 ++-
>>   1 file changed, 2 insertions(+), 1 deletion(-)
> 
> Reviewed-by: Simon Glass <sjg@chromium.org>
> 
> I would have thought that 'unsigned long' is enough on a 64-bit
> machines? Are you running on 32-bit?

I have done it for better code understanding. U-Boot is small and 32bit var is 
big enough. 64bit is more then enough but spec allocates for it 128bits that's 
why it is easier to read that you are actually putting there the whole 128bits.

M

[PATCH 2/3] trace: Move trace_clocks description above record offset calculation

[Michal Simek]

Flyrecord tracing data are page aligned that's why it is necessary to
calculate alignment properly. Because trace_clocks description is the part
of record length it is necessary to have information about length earlier.

Signed-off-by: Michal Simek <michal.simek@amd.com>
---

 tools/proftool.c | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/tools/proftool.c b/tools/proftool.c
index 869a2a32c510..7c95a94482fc 100644
--- a/tools/proftool.c
+++ b/tools/proftool.c
@@ -1500,6 +1500,10 @@ static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
 
 	tw->ptr += fprintf(fout, "flyrecord%c", 0);
 
+	snprintf(str, sizeof(str),
+		 "[local] global counter uptime perf mono mono_raw boot x86-tsc\n");
+	len = strlen(str);
+
 	/* trace data */
 	start = ALIGN(tw->ptr + 16, TRACE_PAGE_SIZE);
 	tw->ptr += tputq(fout, start);
@@ -1510,9 +1514,6 @@ static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
 		return -1;
 	tw->ptr += ret;
 
-	snprintf(str, sizeof(str),
-		 "[local] global counter uptime perf mono mono_raw boot x86-tsc\n");
-	len = strlen(str);
 	tw->ptr += tputq(fout, len);
 	tw->ptr += tputs(fout, str);
 
-- 
2.36.1

Re: [PATCH 2/3] trace: Move trace_clocks description above record offset calculation

[Simon Glass]

On Mon, 11 Sept 2023 at 06:32, Michal Simek <michal.simek@amd.com> wrote:
>
> Flyrecord tracing data are page aligned that's why it is necessary to
> calculate alignment properly. Because trace_clocks description is the part
> of record length it is necessary to have information about length earlier.
>
> Signed-off-by: Michal Simek <michal.simek@amd.com>
> ---
>
>  tools/proftool.c | 7 ++++---
>  1 file changed, 4 insertions(+), 3 deletions(-)
>

Reviewed-by: Simon Glass <sjg@chromium.org>

[PATCH 3/3] trace: Fix alignment logic in flyrecord header

[Michal Simek]

Current alignment which is using 16 bytes is not correct in connection to
trace_clocks description and it's length.
That's why use start_addr variable and record proper size based on used
entries.

Fixes: be16fc81b2ed ("trace: Update proftool to use new binary format").
Signed-off-by: Michal Simek <michal.simek@amd.com>
---

 tools/proftool.c | 31 +++++++++++++++++++++++++++++--
 1 file changed, 29 insertions(+), 2 deletions(-)

diff --git a/tools/proftool.c b/tools/proftool.c
index 7c95a94482fc..f79128169e68 100644
--- a/tools/proftool.c
+++ b/tools/proftool.c
@@ -1493,19 +1493,43 @@ static int write_pages(struct twriter *tw, enum out_format_t out_format,
 static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
 			   int *missing_countp, int *skip_countp)
 {
-	unsigned long long start, len;
+	unsigned long long start, start_addr, len;
 	int ret;
 	FILE *fout = tw->fout;
 	char str[200];
 
+	/* Record start pointer */
+	start_addr = tw->ptr;
+	debug("Start of flyrecord header at: 0x%llx\n", start_addr);
+
 	tw->ptr += fprintf(fout, "flyrecord%c", 0);
 
+	/* flyrecord\0 - allocated 10 bytes */
+	start_addr += 10;
+
+	/*
+	 * 8 bytes that are a 64-bit word containing the offset into the file
+	 * that holds the data for the CPU.
+	 *
+	 * 8 bytes that are a 64-bit word containing the size of the CPU
+	 * data at that offset.
+	 */
+	start_addr += 16;
+
 	snprintf(str, sizeof(str),
 		 "[local] global counter uptime perf mono mono_raw boot x86-tsc\n");
 	len = strlen(str);
 
+	/* trace clock length - 8 bytes */
+	start_addr += 8;
+	/* trace clock data */
+	start_addr += len;
+
+	debug("Calculated flyrecord header end at: 0x%llx, trace clock len: 0x%llx\n",
+	      start_addr, len);
+
 	/* trace data */
-	start = ALIGN(tw->ptr + 16, TRACE_PAGE_SIZE);
+	start = ALIGN(start_addr, TRACE_PAGE_SIZE);
 	tw->ptr += tputq(fout, start);
 
 	/* use a placeholder for the size */
@@ -1517,6 +1541,9 @@ static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
 	tw->ptr += tputq(fout, len);
 	tw->ptr += tputs(fout, str);
 
+	debug("End of flyrecord header at: 0x%x, offset: 0x%llx\n",
+	      tw->ptr, start);
+
 	debug("trace text base %lx, map file %lx\n", text_base, text_offset);
 
 	ret = write_pages(tw, out_format, missing_countp, skip_countp);
-- 
2.36.1

Re: [PATCH 3/3] trace: Fix alignment logic in flyrecord header

[Simon Glass]

Hi Michal,

On Mon, 11 Sept 2023 at 06:32, Michal Simek <michal.simek@amd.com> wrote:
>
> Current alignment which is using 16 bytes is not correct in connection to
> trace_clocks description and it's length.
> That's why use start_addr variable and record proper size based on used
> entries.
>
> Fixes: be16fc81b2ed ("trace: Update proftool to use new binary format").
> Signed-off-by: Michal Simek <michal.simek@amd.com>
> ---
>
>  tools/proftool.c | 31 +++++++++++++++++++++++++++++--
>  1 file changed, 29 insertions(+), 2 deletions(-)
>

Reviewed-by: Simon Glass <sjg@chromium.org>

See my comment below

> diff --git a/tools/proftool.c b/tools/proftool.c
> index 7c95a94482fc..f79128169e68 100644
> --- a/tools/proftool.c
> +++ b/tools/proftool.c
> @@ -1493,19 +1493,43 @@ static int write_pages(struct twriter *tw, enum out_format_t out_format,
>  static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
>                            int *missing_countp, int *skip_countp)
>  {
> -       unsigned long long start, len;
> +       unsigned long long start, start_addr, len;
>         int ret;
>         FILE *fout = tw->fout;
>         char str[200];
>
> +       /* Record start pointer */
> +       start_addr = tw->ptr;

I'd prefer start_ofs since it is not an address, is it?

> +       debug("Start of flyrecord header at: 0x%llx\n", start_addr);
> +
>         tw->ptr += fprintf(fout, "flyrecord%c", 0);
>
> +       /* flyrecord\0 - allocated 10 bytes */
> +       start_addr += 10;
> +
> +       /*
> +        * 8 bytes that are a 64-bit word containing the offset into the file
> +        * that holds the data for the CPU.
> +        *
> +        * 8 bytes that are a 64-bit word containing the size of the CPU
> +        * data at that offset.
> +        */
> +       start_addr += 16;
> +
>         snprintf(str, sizeof(str),
>                  "[local] global counter uptime perf mono mono_raw boot x86-tsc\n");
>         len = strlen(str);
>
> +       /* trace clock length - 8 bytes */
> +       start_addr += 8;
> +       /* trace clock data */
> +       start_addr += len;
> +
> +       debug("Calculated flyrecord header end at: 0x%llx, trace clock len: 0x%llx\n",
> +             start_addr, len);
> +
>         /* trace data */
> -       start = ALIGN(tw->ptr + 16, TRACE_PAGE_SIZE);
> +       start = ALIGN(start_addr, TRACE_PAGE_SIZE);

Would it be possible to store the old tw->ptr value at the top of this
function (e.g. in tw_base) and calculate start using (tw->ptr -
tw_base)? It seems that there are two parallel trackers here.

>         tw->ptr += tputq(fout, start);
>
>         /* use a placeholder for the size */
> @@ -1517,6 +1541,9 @@ static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
>         tw->ptr += tputq(fout, len);
>         tw->ptr += tputs(fout, str);
>
> +       debug("End of flyrecord header at: 0x%x, offset: 0x%llx\n",
> +             tw->ptr, start);
> +
>         debug("trace text base %lx, map file %lx\n", text_base, text_offset);
>
>         ret = write_pages(tw, out_format, missing_countp, skip_countp);
> --
> 2.36.1
>

Regards,
Simon

Re: [PATCH 3/3] trace: Fix alignment logic in flyrecord header

[Michal Simek]

On 9/12/23 21:26, Simon Glass wrote:
> Hi Michal,
> 
> On Mon, 11 Sept 2023 at 06:32, Michal Simek <michal.simek@amd.com> wrote:
>>
>> Current alignment which is using 16 bytes is not correct in connection to
>> trace_clocks description and it's length.
>> That's why use start_addr variable and record proper size based on used
>> entries.
>>
>> Fixes: be16fc81b2ed ("trace: Update proftool to use new binary format").
>> Signed-off-by: Michal Simek <michal.simek@amd.com>
>> ---
>>
>>   tools/proftool.c | 31 +++++++++++++++++++++++++++++--
>>   1 file changed, 29 insertions(+), 2 deletions(-)
>>
> 
> Reviewed-by: Simon Glass <sjg@chromium.org>
> 
> See my comment below
> 
>> diff --git a/tools/proftool.c b/tools/proftool.c
>> index 7c95a94482fc..f79128169e68 100644
>> --- a/tools/proftool.c
>> +++ b/tools/proftool.c
>> @@ -1493,19 +1493,43 @@ static int write_pages(struct twriter *tw, enum out_format_t out_format,
>>   static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
>>                             int *missing_countp, int *skip_countp)
>>   {
>> -       unsigned long long start, len;
>> +       unsigned long long start, start_addr, len;
>>          int ret;
>>          FILE *fout = tw->fout;
>>          char str[200];
>>
>> +       /* Record start pointer */
>> +       start_addr = tw->ptr;
> 
> I'd prefer start_ofs since it is not an address, is it?

make sense.

> 
>> +       debug("Start of flyrecord header at: 0x%llx\n", start_addr);
>> +
>>          tw->ptr += fprintf(fout, "flyrecord%c", 0);
>>
>> +       /* flyrecord\0 - allocated 10 bytes */
>> +       start_addr += 10;
>> +
>> +       /*
>> +        * 8 bytes that are a 64-bit word containing the offset into the file
>> +        * that holds the data for the CPU.
>> +        *
>> +        * 8 bytes that are a 64-bit word containing the size of the CPU
>> +        * data at that offset.
>> +        */
>> +       start_addr += 16;
>> +
>>          snprintf(str, sizeof(str),
>>                   "[local] global counter uptime perf mono mono_raw boot x86-tsc\n");
>>          len = strlen(str);
>>
>> +       /* trace clock length - 8 bytes */
>> +       start_addr += 8;
>> +       /* trace clock data */
>> +       start_addr += len;
>> +
>> +       debug("Calculated flyrecord header end at: 0x%llx, trace clock len: 0x%llx\n",
>> +             start_addr, len);
>> +
>>          /* trace data */
>> -       start = ALIGN(tw->ptr + 16, TRACE_PAGE_SIZE);
>> +       start = ALIGN(start_addr, TRACE_PAGE_SIZE);
> 
> Would it be possible to store the old tw->ptr value at the top of this
> function (e.g. in tw_base) and calculate start using (tw->ptr -
> tw_base)? It seems that there are two parallel trackers here.

I didn't actual dig into that reasons why tw->ptr are used with all that tputq 
logics around.

I was thinking to use minus but because there is trace_clock description on this 
line you are not able to use tw->ptr because it is also changed below. It means 
I decided to do calculation ahead with calculating all bytes which will be 
described here.

Thanks,
Michal