Re: [PATCH v2 16/17] perf tools: Add notion of time to decoding code

On Thu, 6 Jun 2019 at 12:50, Arnaldo Carvalho de Melo arnaldo.melo@gmail.com wrote:

Em Fri, May 24, 2019 at 11:35:07AM -0600, Mathieu Poirier escreveu:

...

This patch deals with timestamp packets received from the decoding library in order to give the front end packet processing loop a handle on the time instruction conveyed by range packets have been executed at.

Signed-off-by: Mathieu Poirier mathieu.poirier@linaro.org

.../perf/util/cs-etm-decoder/cs-etm-decoder.c | 112 +++++++++++++++++- tools/perf/util/cs-etm.c | 19 +++ tools/perf/util/cs-etm.h | 17 +++ 3 files changed, 144 insertions(+), 4 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 ce85e52f989c..33e975c8d11b 100644 --- a/tools/perf/util/cs-etm-decoder/cs-etm-decoder.c +++ b/tools/perf/util/cs-etm-decoder/cs-etm-decoder.c @@ -269,6 +269,76 @@ cs_etm_decoder__create_etm_packet_printer(struct cs_etm_trace_params *t_params, trace_config); }

+static ocsd_datapath_resp_t +cs_etm_decoder__do_soft_timestamp(struct cs_etm_queue *etmq,

•                           struct cs_etm_packet_queue *packet_queue,
  

•                           const uint8_t trace_chan_id)
  

+{

• /* No timestamp packet has been received, nothing to do */
  

• if (!packet_queue->timestamp)
  

•         return OCSD_RESP_CONT;
  

• packet_queue->timestamp = packet_queue->next_timestamp;
  

• /* Estimate the timestamp for the next range packet */
  

• packet_queue->next_timestamp += packet_queue->instr_count;
  

• packet_queue->instr_count = 0;
  

• /* Tell the front end which traceid_queue needs attention */
  

• cs_etm__etmq_set_traceid_queue_timestamp(etmq, trace_chan_id);
  

• return OCSD_RESP_WAIT;
  

+}

+static ocsd_datapath_resp_t +cs_etm_decoder__do_hard_timestamp(struct cs_etm_queue *etmq,

•                           const ocsd_generic_trace_elem *elem,
  

•                           const uint8_t trace_chan_id)
  

+{

• struct cs_etm_packet_queue *packet_queue;
  

• /* First get the packet queue for this traceID */
  

• packet_queue = cs_etm__etmq_get_packet_queue(etmq, trace_chan_id);
  

• if (!packet_queue)
  

•         return OCSD_RESP_FATAL_SYS_ERR;
  

• /*
  

•  * We've seen a timestamp packet before - simply record the new value.
  

•  * Function do_soft_timestamp() will report the value to the front end,
  

•  * hence asking the decoder to keep decoding rather than stopping.
  

•  */
  

• if (packet_queue->timestamp) {
  

•         packet_queue->next_timestamp = elem->timestamp;
  

•         return OCSD_RESP_CONT;
  

• }
  

• /*
  

•  * This is the first timestamp we've seen since the beginning of traces
  

•  * or a discontinuity.  Since timestamps packets are generated *after*
  

•  * range packets have been generated, we need to estimate the time at
  

•  * which instructions started by substracting the number of instructions
  

•  * executed to the timestamp.
  

•  */
  

• packet_queue->timestamp = elem->timestamp -
  

•                                         packet_queue->instr_count;
  

No need to break lines like that, in this case it even wouldn't pass the width used for the comments right above it :-)

I'm fixing it up this time.

Something else, all the patches in this series, so far, needed to have as the subject prefix "perf cs-etm: ...", not the generic one "perf tools: ...". I'm fixing it up as well, no need to resend.

Got that - thanks Mathieu

• Arnaldo

...

• packet_queue->next_timestamp = elem->timestamp;
  

• packet_queue->instr_count = 0;
  

• /* Tell the front end which traceid_queue needs attention */
  

• cs_etm__etmq_set_traceid_queue_timestamp(etmq, trace_chan_id);
  

• /* Halt processing until we are being told to proceed */
  

• return OCSD_RESP_WAIT;
  

+}

+static void +cs_etm_decoder__reset_timestamp(struct cs_etm_packet_queue *packet_queue) +{

• packet_queue->timestamp = 0;
  

• packet_queue->next_timestamp = 0;
  

• packet_queue->instr_count = 0;
  

+}

static ocsd_datapath_resp_t cs_etm_decoder__buffer_packet(struct cs_etm_packet_queue *packet_queue, const u8 trace_chan_id, @@ -310,7 +380,8 @@ cs_etm_decoder__buffer_packet(struct cs_etm_packet_queue *packet_queue, }

static ocsd_datapath_resp_t -cs_etm_decoder__buffer_range(struct cs_etm_packet_queue *packet_queue, +cs_etm_decoder__buffer_range(struct cs_etm_queue *etmq,

•                      struct cs_etm_packet_queue *packet_queue,
                       const ocsd_generic_trace_elem *elem,
                       const uint8_t trace_chan_id)
  

{ @@ -365,6 +436,23 @@ cs_etm_decoder__buffer_range(struct cs_etm_packet_queue *packet_queue,

  packet->last_instr_size = elem->last_instr_sz;

• /* per-thread scenario, no need to generate a timestamp */
  

• if (cs_etm__etmq_is_timeless(etmq))
  

•         goto out;
  

• /*
  

•  * The packet queue is full and we haven't seen a timestamp (had we
  

•  * seen one the packet queue wouldn't be full).  Let the front end
  

•  * deal with it.
  

•  */
  

• if (ret == OCSD_RESP_WAIT)
  

•         goto out;
  

• packet_queue->instr_count += elem->num_instr_range;
  

• /* Tell the front end we have a new timestamp to process */
  

• ret = cs_etm_decoder__do_soft_timestamp(etmq, packet_queue,
  

•                                         trace_chan_id);
  

+out: return ret; }

@@ -372,6 +460,11 @@ static ocsd_datapath_resp_t cs_etm_decoder__buffer_discontinuity(struct cs_etm_packet_queue *queue, const uint8_t trace_chan_id) {

• /*
  

•  * Something happened and who knows when we'll get new traces so
  

•  * reset time statistics.
  

•  */
  

• cs_etm_decoder__reset_timestamp(queue);
  return cs_etm_decoder__buffer_packet(queue, trace_chan_id,
                                       CS_ETM_DISCONTINUITY);
  

} @@ -404,6 +497,7 @@ cs_etm_decoder__buffer_exception_ret(struct cs_etm_packet_queue *queue,

static ocsd_datapath_resp_t cs_etm_decoder__set_tid(struct cs_etm_queue *etmq,

•                 struct cs_etm_packet_queue *packet_queue,
                  const ocsd_generic_trace_elem *elem,
                  const uint8_t trace_chan_id)
  

{ @@ -417,6 +511,12 @@ cs_etm_decoder__set_tid(struct cs_etm_queue *etmq, if (cs_etm__etmq_set_tid(etmq, tid, trace_chan_id)) return OCSD_RESP_FATAL_SYS_ERR;

• /*
  

•  * A timestamp is generated after a PE_CONTEXT element so make sure
  

•  * to rely on that coming one.
  

•  */
  

• cs_etm_decoder__reset_timestamp(packet_queue);
  

• return OCSD_RESP_CONT;
  

}

@@ -446,7 +546,7 @@ static ocsd_datapath_resp_t cs_etm_decoder__gen_trace_elem_printer( trace_chan_id); break; case OCSD_GEN_TRC_ELEM_INSTR_RANGE:

•         resp = cs_etm_decoder__buffer_range(packet_queue, elem,
  

•         resp = cs_etm_decoder__buffer_range(etmq, packet_queue, elem,
                                              trace_chan_id);
          break;
  case OCSD_GEN_TRC_ELEM_EXCEPTION:
  

@@ -457,11 +557,15 @@ static ocsd_datapath_resp_t cs_etm_decoder__gen_trace_elem_printer( resp = cs_etm_decoder__buffer_exception_ret(packet_queue, trace_chan_id); break;

• case OCSD_GEN_TRC_ELEM_TIMESTAMP:
  

•         resp = cs_etm_decoder__do_hard_timestamp(etmq, elem,
  

•                                                  trace_chan_id);
  

•         break;
  case OCSD_GEN_TRC_ELEM_PE_CONTEXT:
  

•         resp = cs_etm_decoder__set_tid(etmq, elem, trace_chan_id);
  

•         resp = cs_etm_decoder__set_tid(etmq, packet_queue,
  

•                                        elem, trace_chan_id);
          break;
  case OCSD_GEN_TRC_ELEM_ADDR_NACC:
  

• case OCSD_GEN_TRC_ELEM_TIMESTAMP:
  case OCSD_GEN_TRC_ELEM_CYCLE_COUNT:
  case OCSD_GEN_TRC_ELEM_ADDR_UNKNOWN:
  case OCSD_GEN_TRC_ELEM_EVENT:
  

diff --git a/tools/perf/util/cs-etm.c b/tools/perf/util/cs-etm.c index 17adf554b679..91496a3a2209 100644 --- a/tools/perf/util/cs-etm.c +++ b/tools/perf/util/cs-etm.c @@ -80,6 +80,7 @@ struct cs_etm_queue { struct cs_etm_decoder *decoder; struct auxtrace_buffer *buffer; unsigned int queue_nr;

• u8 pending_timestamp;
  u64 offset;
  const unsigned char *buf;
  size_t buf_len, buf_used;
  

@@ -133,6 +134,19 @@ int cs_etm__get_cpu(u8 trace_chan_id, int *cpu) return 0; }

+void cs_etm__etmq_set_traceid_queue_timestamp(struct cs_etm_queue *etmq,

•                                       u8 trace_chan_id)
  

+{

• /*
  

•  * Wnen a timestamp packet is encountered the backend code
  

•  * is stopped so that the front end has time to process packets
  

•  * that were accumulated in the traceID queue.  Since there can
  

•  * be more than one channel per cs_etm_queue, we need to specify
  

•  * what traceID queue needs servicing.
  

•  */
  

• etmq->pending_timestamp = trace_chan_id;
  

+}

static void cs_etm__clear_packet_queue(struct cs_etm_packet_queue *queue) { int i; @@ -942,6 +956,11 @@ int cs_etm__etmq_set_tid(struct cs_etm_queue *etmq, return 0; }

+bool cs_etm__etmq_is_timeless(struct cs_etm_queue *etmq) +{

• return !!etmq->etm->timeless_decoding;
  

+}

static int cs_etm__synth_instruction_sample(struct cs_etm_queue *etmq, struct cs_etm_traceid_queue *tidq, u64 addr, u64 period) diff --git a/tools/perf/util/cs-etm.h b/tools/perf/util/cs-etm.h index b2a7628620bf..33b57e748c3d 100644 --- a/tools/perf/util/cs-etm.h +++ b/tools/perf/util/cs-etm.h @@ -150,6 +150,9 @@ struct cs_etm_packet_queue { u32 packet_count; u32 head; u32 tail;

• u32 instr_count;
  

• u64 timestamp;
  

• u64 next_timestamp;
  struct cs_etm_packet packet_buffer[CS_ETM_PACKET_MAX_BUFFER];
  

};

@@ -183,6 +186,9 @@ int cs_etm__process_auxtrace_info(union perf_event *event, int cs_etm__get_cpu(u8 trace_chan_id, int *cpu); int cs_etm__etmq_set_tid(struct cs_etm_queue *etmq, pid_t tid, u8 trace_chan_id); +bool cs_etm__etmq_is_timeless(struct cs_etm_queue *etmq); +void cs_etm__etmq_set_traceid_queue_timestamp(struct cs_etm_queue *etmq,

•                                       u8 trace_chan_id);
  

struct cs_etm_packet_queue *cs_etm__etmq_get_packet_queue(struct cs_etm_queue *etmq, u8 trace_chan_id); #else @@ -207,6 +213,17 @@ static inline int cs_etm__etmq_set_tid( return -1; }

+static inline bool cs_etm__etmq_is_timeless(

•                         struct cs_etm_queue *etmq __maybe_unused)
  

+{

• /* What else to return? */
  

• return true;
  

+}

+static inline void cs_etm__etmq_set_traceid_queue_timestamp(

•                         struct cs_etm_queue *etmq __maybe_unused,
  

•                         u8 trace_chan_id __maybe_unused) {}
  

static inline struct cs_etm_packet_queue *cs_etm__etmq_get_packet_queue( struct cs_etm_queue *etmq __maybe_unused, u8 trace_chan_id __maybe_unused) -- 2.17.1

--

• Arnaldo