Iotrace improvements

Signed-off-by Ramon Fried <[email protected]>

---
 cmd/iotrace.c | 22 ++++++++++++++++++++++
 1 file changed, 22 insertions(+)

When dealing with a lot of IO regions, sometimes
it makes sense only to trace a specific one.
This patch adds support for region limits.
If region is not set, the iotrace works the same as it was. If region is set, the iotrace only logs io operation that falls in the defined region.

Signed-off-by Ramon Fried <[email protected]>

---
 common/iotrace.c  | 27 +++++++++++++++++++++++++++
 include/iotrace.h | 24 ++++++++++++++++++++++++
 2 files changed, 51 insertions(+)

Add timestamp to each iotrace record to aid in debugging of IO timing access bugs.

Signed-off-by Ramon Fried <[email protected]>

---
 common/iotrace.c | 3 +++
 1 file changed, 3 insertions(+)

common/iotrace.c +2 -0

index f39885663a..3530688ab1 100644
@@ -27,11 +27,13 @@ enum iotrace_flags {
  * struct iotrace_record - Holds a single I/O trace record
  *
  * @flags: I/O access type
+ * @timestamp: Timestamp of access
  * @addr: Address of access
  * @value: Value written or read
  */
 struct iotrace_record {
        enum iotrace_flags flags;
+       u64 timestamp;
        phys_addr_t addr;
        iovalue_t value;
 };

common/iotrace.c +0 -1

        rec->flags = flags;
        rec->addr = map_to_sysmem(ptr);
        rec->value = value;
--

2.17.0

HI Ramon,

Quoted 30 lines · Ramon Fried

Add timestamp to each iotrace record to aid in debugging of IO timing access bugs.

Signed-off-by Ramon Fried <[email protected]>

---
 common/iotrace.c | 3 +++
 1 file changed, 3 insertions(+)

common/iotrace.c +2 -0

index f39885663a..3530688ab1 100644
@@ -27,11 +27,13 @@ enum iotrace_flags {
  * struct iotrace_record - Holds a single I/O trace record
  *
  * @flags: I/O access type
+ * @timestamp: Timestamp of access
  * @addr: Address of access
  * @value: Value written or read
  */
 struct iotrace_record {
        enum iotrace_flags flags;
+       u64 timestamp;
        phys_addr_t addr;
        iovalue_t value;
 };

@@ -82,6 +84,7 @@ static void add_record(int flags, const void *ptr, ulong value)
                                        sizeof(value));
        }
 

common/iotrace.c static void add_record(int flags, const void *ptr, ulong value) · line 87

Quoted 1 line

common/iotrace.c +1 -0

+       rec->timestamp = get_ticks();

Would it not be better to use timer_get_us() here?

Quoted 7 lines

common/iotrace.c +0 -1

        rec->flags = flags;
        rec->addr = map_to_sysmem(ptr);
        rec->value = value;
--

2.17.0

Regards,
Simon

The header definitions are needed for reading
record information in cmd/iotrace.c

Signed-off-by Ramon Fried <[email protected]>

---
 common/iotrace.c  | 27 ---------------------------
 include/iotrace.h | 28 ++++++++++++++++++++++++++++
 2 files changed, 28 insertions(+), 27 deletions(-)

Add dump trace command which dump all trace
buffer content in a much more readable fashion
than md.

Signed-off-by Ramon Fried <[email protected]>

---
v2: fixed printf zero field width.

 cmd/iotrace.c | 36 +++++++++++++++++++++++++++++++++++-
 1 file changed, 35 insertions(+), 1 deletion(-)

When the buffer is full, there supposed to be no more writes, the code however misses the else statement and subsequently writes to arbitrary pointer location and increases the offset.

This patch fixes that by returning immediately.

Signed-off-by Ramon Fried <[email protected]>

---
 common/iotrace.c | 2 ++
 1 file changed, 2 insertions(+)

common/iotrace.c +2 -1

index 74408a5dbb..5f06d2b250 100644
@@ -55,6 +55,8 @@ static void add_record(int flags, const void *ptr, ulong value)
                rec = (struct iotrace_record *)map_sysmem(
                                        iotrace.start + iotrace.offset,
                                        sizeof(value));
+       } else {
+               return;
        }
 
        rec->timestamp = get_ticks();
--

2.17.0

Hi Ramon,

Quoted 4 lines · Ramon Fried

When the buffer is full, there supposed to be no more writes, the code however misses the else statement and subsequently writes to arbitrary pointer location and increases the offset.

I don't think so. It writes to a local variable in this case. The point of this is to detect how much space would be needed to hold the I/O trace. Unless the pointer is incremented, there is no way to know.

Perhaps instead, iotrace_get_buffer() should be updated to also return the number of valid records, as well as the pointer value?

Quoted 21 lines

This patch fixes that by returning immediately.

Signed-off-by Ramon Fried <[email protected]>

---
 common/iotrace.c | 2 ++
 1 file changed, 2 insertions(+)

common/iotrace.c +2 -1

index 74408a5dbb..5f06d2b250 100644
@@ -55,6 +55,8 @@ static void add_record(int flags, const void *ptr, ulong value)
                rec = (struct iotrace_record *)map_sysmem(
                                        iotrace.start + iotrace.offset,
                                        sizeof(value));
+       } else {
+               return;
        }
 
        rec->timestamp = get_ticks();
--

Quoted 2 lines

2.17.0

Regards,
Simon

Quoted 11 lines · Simon Glass

Hi Ramon,

Quoted 4 lines · Ramon Fried

When the buffer is full, there supposed to be no more writes, the code however misses the else statement and subsequently writes to arbitrary pointer location and increases the offset.

I don't think so. It writes to a local variable in this case. The point of this is to detect how much space would be needed to hold the I/O trace. Unless the pointer is incremented, there is no way to know.

You're right. I missed the initial assignment to rec.

Quoted 1 line

Quoted 3 lines

Perhaps instead, iotrace_get_buffer() should be updated to also return the number of valid records, as well as the pointer value?

It's a valid option, another one I have in mind is that we can return immediately like I suggested but add one time warning that states that the
buffer is full ?

Hi Ramon,

Quoted 15 lines · Ramon Fried

Quoted 11 lines · Simon Glass

Hi Ramon,

Quoted 4 lines · Ramon Fried

When the buffer is full, there supposed to be no more writes, the code however misses the else statement and subsequently writes to arbitrary pointer location and increases the offset.

I don't think so. It writes to a local variable in this case. The point of this is to detect how much space would be needed to hold the I/O trace. Unless the pointer is incremented, there is no way to know.

You're right. I missed the initial assignment to rec.

Quoted 1 line

Quoted 7 lines

Quoted 3 lines

Perhaps instead, iotrace_get_buffer() should be updated to also return the number of valid records, as well as the pointer value?

It's a valid option, another one I have in mind is that we can return immediately like I suggested but add one time warning that states that the
buffer is full ?

The problem is that people want to be able to resize the buffer so that they can try again, so they need to know the correct size.

Can you make it report that it overflowed, and print the correct size?

Regards,
Simon

Quoted 29 lines · Simon Glass

Hi Ramon,

Quoted 15 lines · Ramon Fried

Quoted 11 lines · Simon Glass

Hi Ramon,

Quoted 4 lines · Ramon Fried

When the buffer is full, there supposed to be no more writes, the code however misses the else statement and subsequently writes to arbitrary pointer location and increases the offset.

I don't think so. It writes to a local variable in this case. The point of this is to detect how much space would be needed to hold the I/O trace. Unless the pointer is incremented, there is no way to know.

You're right. I missed the initial assignment to rec.

Quoted 1 line

Quoted 7 lines

Quoted 3 lines

Perhaps instead, iotrace_get_buffer() should be updated to also return the number of valid records, as well as the pointer value?

It's a valid option, another one I have in mind is that we can return immediately like I suggested but add one time warning that states that the
buffer is full ?

The problem is that people want to be able to resize the buffer so that they can try again, so they need to know the correct size.

Quoted 1 line

Can you make it report that it overflowed, and print the correct size?

The correct size can only be printed in the end of the tracing. Maybe we can use WARN_ONCE when it first occurs and later when the user type "iotrace stats" it will state the required buffer size to accommodate all of the
entries.
What do you think ?