Re: [RFC PATCH] perf cs-etm: Handle valid-but-zero timestamps

From: Mike Leach
Date: Fri May 07 2021 - 10:09:49 EST


Hi James,

1) Not sure about this particular target - but previously all 0
timestamps have been the result of not enabling a clock or the
coresight timestamp generator.

2) Given that you can synthesise timestamps when all the values are
all 0 - does this not imply that they could be synthesised when they
are not present at all?

Cheers

Mike

On Fri, 7 May 2021 at 11:02, James Clark <james.clark@xxxxxxx> wrote:
>
>
>
> On 07/05/2021 12:58, James Clark wrote:
> > There is an intermittent issue on Trogdor devices that
> > results in all Coresight timestamps having a value of zero.
>
> I've attached a file here that has the issue. From the dump you
> can see the zero timestamps:
>
> Idx:69; ID:10; I_TIMESTAMP : Timestamp.; Updated val = 0x0
> Idx:71; ID:10; I_ATOM_F1 : Atom format 1.; E
> Idx:72; ID:10; I_ADDR_S_IS0 : Address, Short, IS0.; Addr=0xFFFFFFE723C65824 ~[0x5824]
>
> This doesn't have an impact on decoding as they end up being
> decoded in file order as in with timeless mode.
>
> James
>
> > Because zero is currently treated as "not found" rather
> > than "found but zero", this breaks the decoding flow
> > when it would otherwise work.
> >
> > This patch adds an out parameter and return code so
> > the difference between zero and non-existent timestamps
> > can be determined.
> >
> > There is also a change to fix an underflow.
> >
> > Although this is a workaround, the change is technically
> > a valid way of writing the cs_etm__etmq_get_timestamp()
> > function. It could have been written similarly to this
> > without trying to work around this issue, so it's no less
> > correct. But, because it's a workaround to a problem
> > elsewhere, I will submit this as an RFC for feedback.
> >
> > This patch applies on top of the "[PATCH v2 0/2] perf
> > cs-etm: Set time on synthesised samples to preserve ordering"
> > patchset.
> >
> > Co-developed-by: Denis Nikitin <denik@xxxxxxxxxxxx>
> > Signed-off-by: Denis Nikitin <denik@xxxxxxxxxxxx>
> > Signed-off-by: James Clark <james.clark@xxxxxxx>
> > ---
> > .../perf/util/cs-etm-decoder/cs-etm-decoder.c | 5 ++++-
> > tools/perf/util/cs-etm.c | 22 +++++++++----------
> > 2 files changed, 15 insertions(+), 12 deletions(-)
> >
> > diff --git a/tools/perf/util/cs-etm-decoder/cs-etm-decoder.c b/tools/perf/util/cs-etm-decoder/cs-etm-decoder.c
> > index b01d363b9301..947e44413c6e 100644
> > --- a/tools/perf/util/cs-etm-decoder/cs-etm-decoder.c
> > +++ b/tools/perf/util/cs-etm-decoder/cs-etm-decoder.c
> > @@ -320,7 +320,10 @@ cs_etm_decoder__do_hard_timestamp(struct cs_etm_queue *etmq,
> > * which instructions started by subtracting the number of instructions
> > * executed to the timestamp.
> > */
> > - packet_queue->cs_timestamp = elem->timestamp - packet_queue->instr_count;
> > + if (packet_queue->instr_count >= elem->timestamp)
> > + packet_queue->cs_timestamp = 0;
> > + else
> > + packet_queue->cs_timestamp = elem->timestamp - packet_queue->instr_count;
> > packet_queue->next_cs_timestamp = elem->timestamp;
> > packet_queue->instr_count = 0;
> >
> > diff --git a/tools/perf/util/cs-etm.c b/tools/perf/util/cs-etm.c
> > index e5c1a1b22a2a..1969921c406a 100644
> > --- a/tools/perf/util/cs-etm.c
> > +++ b/tools/perf/util/cs-etm.c
> > @@ -210,13 +210,14 @@ void cs_etm__etmq_set_traceid_queue_timestamp(struct cs_etm_queue *etmq,
> > etmq->pending_timestamp_chan_id = trace_chan_id;
> > }
> >
> > -static u64 cs_etm__etmq_get_timestamp(struct cs_etm_queue *etmq,
> > +static int cs_etm__etmq_get_timestamp(struct cs_etm_queue *etmq,
> > + u64 *timestamp,
> > u8 *trace_chan_id)
> > {
> > struct cs_etm_packet_queue *packet_queue;
> >
> > if (!etmq->pending_timestamp_chan_id)
> > - return 0;
> > + return -ENODATA;
> >
> > if (trace_chan_id)
> > *trace_chan_id = etmq->pending_timestamp_chan_id;
> > @@ -224,13 +225,15 @@ static u64 cs_etm__etmq_get_timestamp(struct cs_etm_queue *etmq,
> > packet_queue = cs_etm__etmq_get_packet_queue(etmq,
> > etmq->pending_timestamp_chan_id);
> > if (!packet_queue)
> > - return 0;
> > + return -ENODATA;
> >
> > /* Acknowledge pending status */
> > etmq->pending_timestamp_chan_id = 0;
> >
> > /* See function cs_etm_decoder__do_{hard|soft}_timestamp() */
> > - return packet_queue->cs_timestamp;
> > + if (timestamp)
> > + *timestamp = packet_queue->cs_timestamp;
> > + return 0;
> > }
> >
> > static void cs_etm__clear_packet_queue(struct cs_etm_packet_queue *queue)
> > @@ -864,11 +867,10 @@ static int cs_etm__setup_queue(struct cs_etm_auxtrace *etm,
> > * Function cs_etm_decoder__do_{hard|soft}_timestamp() does all
> > * the timestamp calculation for us.
> > */
> > - cs_timestamp = cs_etm__etmq_get_timestamp(etmq, &trace_chan_id);
> > -
> > - /* We found a timestamp, no need to continue. */
> > - if (cs_timestamp)
> > + if (!cs_etm__etmq_get_timestamp(etmq, &cs_timestamp, &trace_chan_id)) {
> > + /* We found a timestamp, no need to continue. */
> > break;
> > + }
> >
> > /*
> > * We didn't find a timestamp so empty all the traceid packet
> > @@ -2286,9 +2288,7 @@ static int cs_etm__process_queues(struct cs_etm_auxtrace *etm)
> > if (ret)
> > goto out;
> >
> > - cs_timestamp = cs_etm__etmq_get_timestamp(etmq, &trace_chan_id);
> > -
> > - if (!cs_timestamp) {
> > + if (cs_etm__etmq_get_timestamp(etmq, &cs_timestamp, &trace_chan_id)) {
> > /*
> > * Function cs_etm__decode_data_block() returns when
> > * there is no more traces to decode in the current
> >



--
Mike Leach
Principal Engineer, ARM Ltd.
Manchester Design Centre. UK