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

[Denis Nikitin]

Hi Mike,

1. This is a different issue and it's already confirmed as the hw bug.
Reset of the coresight generator may happen at any time and
it goes to normal only after the device reboot.

Thanks,
Denis


On Fri, May 7, 2021 at 7:09 AM Mike Leach <mike.leach@xxxxxxxxxx> wrote:
>
> 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