Merge branch 'ap-bus-trace-events'

Harald Freudenberger says:

====================

Investigations related to runtime of crypto requests has revealed a lack of
performance or runtime information with crypto requests. There are the two
zcrypt ioctl trace events covering the entry and exit of an ioctl with
crypto requests giving the overall runtime within the kernel. However,
there is no way to figure out the time where a request is enqueued into the
AP bus queue but not pushed into the firmware queue. Then there is no
information about the runtime of an request during processing in the
firmware. And finally some info about pulling the reply from the firmware
and delivering it into user space is missing.

This series is aiming to provide a way to collect measurements which can be
used to cover these runtime information for each crypto request/reply.

====================

Signed-off-by: Heiko Carstens <hca@linux.ibm.com>

5 files changed, 161 insertions, 34 deletions

diff --git a/arch/s390/include/asm/ap.h b/arch/s390/include/asm/ap.h
index 56817990c73d..b24459f692fa 100644
--- a/arch/s390/include/asm/ap.h
+++ b/arch/s390/include/asm/ap.h
@@ -38,16 +38,30 @@ typedef unsigned int ap_qid_t;
  * The ap queue status word is returned by all three AP functions
  * (PQAP, NQAP and DQAP).  There's a set of flags in the first
  * byte, followed by a 1 byte response code.
+ *
+ * For convenience the 'value' field is a 32 bit access of the
+ * whole status and the 'status_bits' and 'rc' fields comprise
+ * the leftmost 8 status bits and the response_code.
  */
 struct ap_queue_status {
-	unsigned int queue_empty	: 1;
-	unsigned int replies_waiting	: 1;
-	unsigned int queue_full		: 1;
-	unsigned int			: 3;
-	unsigned int async		: 1;
-	unsigned int irq_enabled	: 1;
-	unsigned int response_code	: 8;
-	unsigned int			: 16;
+	union {
+		unsigned int value			: 32;
+		struct {
+			unsigned int status_bits	: 8;
+			unsigned int rc			: 8;
+			unsigned int			: 16;
+		};
+		struct {
+			unsigned int queue_empty	: 1;
+			unsigned int replies_waiting	: 1;
+			unsigned int queue_full		: 1;
+			unsigned int			: 3;
+			unsigned int async		: 1;
+			unsigned int irq_enabled	: 1;
+			unsigned int response_code	: 8;
+			unsigned int			: 16;
+		};
+	};
 };
 
 /*
diff --git a/arch/s390/include/asm/trace/ap.h b/arch/s390/include/asm/trace/ap.h
new file mode 100644
index 000000000000..5c2e6c664b4d
--- /dev/null
+++ b/arch/s390/include/asm/trace/ap.h
@@ -0,0 +1,87 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+/*
+ * Tracepoint definitions for s390 ap bus related trace events
+ *
+ * There are two AP bus related tracepoint events defined here:
+ * There is a tracepoint s390_ap_nqap event immediately after a request
+ * has been pushed into the AP firmware queue with the NQAP AP command.
+ * The other tracepoint s390_ap_dqap event fires immediately after a
+ * reply has been pulled out of the AP firmware queue via DQAP AP command.
+ * The idea of these two trace events focuses on performance to measure
+ * the runtime of a crypto request/reply as close as possible at the
+ * firmware level. In combination with the two zcrypt tracepoints (see the
+ * zcrypt.h trace event definition file) this gives measurement data about
+ * the runtime of a request/reply within the zcrpyt and AP bus layer.
+ */
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM s390
+
+#if !defined(_TRACE_S390_AP_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_S390_AP_H
+
+#include <linux/tracepoint.h>
+
+DECLARE_EVENT_CLASS(s390_ap_nqapdqap_template,
+		    TP_PROTO(u16 card, u16 dom, u32 status, u64 psmid),
+		    TP_ARGS(card, dom, status, psmid),
+		    TP_STRUCT__entry(
+			    __field(u16, card)
+			    __field(u16, dom)
+			    __field(u32, status)
+			    __field(u64, psmid)),
+		    TP_fast_assign(
+			    __entry->card = card;
+			    __entry->dom = dom;
+			    __entry->status = status;
+			    __entry->psmid = psmid;),
+		    TP_printk("card=%u dom=%u status=0x%08x psmid=0x%016lx",
+			      (unsigned short)__entry->card,
+			      (unsigned short)__entry->dom,
+			      (unsigned int)__entry->status,
+			      (unsigned long)__entry->psmid)
+);
+
+/**
+ * trace_s390_ap_nqap - ap msg nqap tracepoint function
+ * @card:   Crypto card number addressed.
+ * @dom:    Domain within the crypto card addressed.
+ * @status: AP queue status (GR1 on return of nqap).
+ * @psmid:  Unique id identifying this request/reply.
+ *
+ * Called immediately after a request has been enqueued into
+ * the AP firmware queue with the NQAP command.
+ */
+DEFINE_EVENT(s390_ap_nqapdqap_template,
+	     s390_ap_nqap,
+	     TP_PROTO(u16 card, u16 dom, u32 status, u64 psmid),
+	     TP_ARGS(card, dom, status, psmid)
+);
+
+/**
+ * trace_s390_ap_dqap - ap msg dqap tracepoint function
+ * @card:  Crypto card number addressed.
+ * @dom:   Domain within the crypto card addressed.
+ * @status: AP queue status (GR1 on return of dqap).
+ * @psmid: Unique id identifying this request/reply.
+ *
+ * Called immediately after a reply has been dequeued from
+ * the AP firmware queue with the DQAP command.
+ */
+DEFINE_EVENT(s390_ap_nqapdqap_template,
+	     s390_ap_dqap,
+	     TP_PROTO(u16 card, u16 dom, u32 status, u64 psmid),
+	     TP_ARGS(card, dom, status, psmid)
+);
+
+#endif /* _TRACE_S390_AP_H */
+
+/* This part must be outside protection */
+
+#undef TRACE_INCLUDE_PATH
+#undef TRACE_INCLUDE_FILE
+
+#define TRACE_INCLUDE_PATH asm/trace
+#define TRACE_INCLUDE_FILE ap
+
+#include <trace/define_trace.h>
diff --git a/arch/s390/include/asm/trace/zcrypt.h b/arch/s390/include/asm/trace/zcrypt.h
index 457ddaa99e19..bfb01e335f31 100644
--- a/arch/s390/include/asm/trace/zcrypt.h
+++ b/arch/s390/include/asm/trace/zcrypt.h
@@ -2,7 +2,7 @@
 /*
  * Tracepoint definitions for the s390 zcrypt device driver
  *
- * Copyright IBM Corp. 2016
+ * Copyright IBM Corp. 2016,2025
  * Author(s): Harald Freudenberger <freude@de.ibm.com>
  *
  * Currently there are two tracepoint events defined here.
@@ -73,14 +73,15 @@ TRACE_EVENT(s390_zcrypt_req,
 
 /**
  * trace_s390_zcrypt_rep - zcrypt reply tracepoint function
- * @ptr:  Address of the local buffer where the request from userspace
- *	  is stored. Can be used as a unique id to match together
- *	  request and reply.
- * @fc:   Function code.
- * @rc:   The bare returncode as returned by the device driver ioctl
- *	  function.
- * @dev:  The adapter nr where this request was actually processed.
- * @dom:  Domain id of the device where this request was processed.
+ * @ptr:   Address of the local buffer where the request from userspace
+ *	   is stored. Can be used as a unique id to match together
+ *	   request and reply.
+ * @fc:    Function code.
+ * @rc:    The bare returncode as returned by the device driver ioctl
+ *	   function.
+ * @card:  The adapter nr where this request was actually processed.
+ * @dom:   Domain id of the device where this request was processed.
+ * @psmid: Unique id identifying this request/reply.
  *
  * Called upon recognising the reply from the crypto adapter. This
  * message may act as the exit timestamp for the request but also
@@ -88,26 +89,29 @@ TRACE_EVENT(s390_zcrypt_req,
  * and the returncode from the device driver.
  */
 TRACE_EVENT(s390_zcrypt_rep,
-	    TP_PROTO(void *ptr, u32 fc, u32 rc, u16 dev, u16 dom),
-	    TP_ARGS(ptr, fc, rc, dev, dom),
+	    TP_PROTO(void *ptr, u32 fc, u32 rc, u16 card, u16 dom, u64 psmid),
+	    TP_ARGS(ptr, fc, rc, card, dom, psmid),
 	    TP_STRUCT__entry(
 		    __field(void *, ptr)
 		    __field(u32, fc)
 		    __field(u32, rc)
-		    __field(u16, device)
-		    __field(u16, domain)),
+		    __field(u16, card)
+		    __field(u16, dom)
+		    __field(u64, psmid)),
 	    TP_fast_assign(
 		    __entry->ptr = ptr;
 		    __entry->fc = fc;
 		    __entry->rc = rc;
-		    __entry->device = dev;
-		    __entry->domain = dom;),
-	    TP_printk("ptr=%p fc=0x%04x rc=%d dev=0x%02hx domain=0x%04hx",
+		    __entry->card = card;
+		    __entry->dom = dom;
+		    __entry->psmid = psmid;),
+	    TP_printk("ptr=%p fc=0x%04x rc=%d card=%u dom=%u psmid=0x%016lx",
 		      __entry->ptr,
-		      (unsigned int) __entry->fc,
-		      (int) __entry->rc,
-		      (unsigned short) __entry->device,
-		      (unsigned short) __entry->domain)
+		      (unsigned int)__entry->fc,
+		      (int)__entry->rc,
+		      (unsigned short)__entry->card,
+		      (unsigned short)__entry->dom,
+		      (unsigned long)__entry->psmid)
 );
 
 #endif /* _TRACE_S390_ZCRYPT_H */
diff --git a/drivers/s390/crypto/ap_queue.c b/drivers/s390/crypto/ap_queue.c
index 8977866fab1b..579e421d134c 100644
--- a/drivers/s390/crypto/ap_queue.c
+++ b/drivers/s390/crypto/ap_queue.c
@@ -14,9 +14,15 @@
 #include <linux/slab.h>
 #include <asm/facility.h>
 
+#define CREATE_TRACE_POINTS
+#include <asm/trace/ap.h>
+
 #include "ap_bus.h"
 #include "ap_debug.h"
 
+EXPORT_TRACEPOINT_SYMBOL(s390_ap_nqap);
+EXPORT_TRACEPOINT_SYMBOL(s390_ap_dqap);
+
 static void __ap_flush_queue(struct ap_queue *aq);
 
 /*
@@ -98,9 +104,17 @@ static inline struct ap_queue_status
 __ap_send(ap_qid_t qid, unsigned long psmid, void *msg, size_t msglen,
 	  int special)
 {
+	struct ap_queue_status status;
+
 	if (special)
 		qid |= 0x400000UL;
-	return ap_nqap(qid, psmid, msg, msglen);
+
+	status = ap_nqap(qid, psmid, msg, msglen);
+
+	trace_s390_ap_nqap(AP_QID_CARD(qid), AP_QID_QUEUE(qid),
+			   status.value, psmid);
+
+	return status;
 }
 
 /* State machine definitions and helpers */
@@ -140,6 +154,9 @@ static struct ap_queue_status ap_sm_recv(struct ap_queue *aq)
 		parts++;
 	} while (status.response_code == 0xFF && resgr0 != 0);
 
+	trace_s390_ap_dqap(AP_QID_CARD(aq->qid), AP_QID_QUEUE(aq->qid),
+			   status.value, aq->reply->psmid);
+
 	switch (status.response_code) {
 	case AP_RESPONSE_NORMAL:
 		print_hex_dump_debug("aprpl: ", DUMP_PREFIX_ADDRESS, 16, 1,
diff --git a/drivers/s390/crypto/zcrypt_api.c b/drivers/s390/crypto/zcrypt_api.c
index 4e6bf1cb3475..2b67b6b02ad5 100644
--- a/drivers/s390/crypto/zcrypt_api.c
+++ b/drivers/s390/crypto/zcrypt_api.c
@@ -740,7 +740,8 @@ out:
 		tr->last_qid = qid;
 	}
 	trace_s390_zcrypt_rep(mex, func_code, rc,
-			      AP_QID_CARD(qid), AP_QID_QUEUE(qid));
+			      AP_QID_CARD(qid), AP_QID_QUEUE(qid),
+			      ap_msg.psmid);
 	return rc;
 }
 
@@ -845,7 +846,8 @@ out:
 		tr->last_qid = qid;
 	}
 	trace_s390_zcrypt_rep(crt, func_code, rc,
-			      AP_QID_CARD(qid), AP_QID_QUEUE(qid));
+			      AP_QID_CARD(qid), AP_QID_QUEUE(qid),
+			      ap_msg.psmid);
 	return rc;
 }
 
@@ -980,7 +982,8 @@ out:
 		tr->last_qid = qid;
 	}
 	trace_s390_zcrypt_rep(xcrb, func_code, rc,
-			      AP_QID_CARD(qid), AP_QID_QUEUE(qid));
+			      AP_QID_CARD(qid), AP_QID_QUEUE(qid),
+			      ap_msg.psmid);
 	return rc;
 }
 
@@ -1182,7 +1185,8 @@ out:
 		tr->last_qid = qid;
 	}
 	trace_s390_zcrypt_rep(xcrb, func_code, rc,
-			      AP_QID_CARD(qid), AP_QID_QUEUE(qid));
+			      AP_QID_CARD(qid), AP_QID_QUEUE(qid),
+			      ap_msg.psmid);
 	return rc;
 }
 
@@ -1274,7 +1278,8 @@ static long zcrypt_rng(char *buffer)
 out:
 	ap_release_apmsg(&ap_msg);
 	trace_s390_zcrypt_rep(buffer, func_code, rc,
-			      AP_QID_CARD(qid), AP_QID_QUEUE(qid));
+			      AP_QID_CARD(qid), AP_QID_QUEUE(qid),
+			      ap_msg.psmid);
 	return rc;
 }