mkbp: take timestamp closer to hardware interrupt

We want to ensure that the timestamp we take for last mkbp is as close
to the actual hardware interrupt from EC->AP.

BRANCH=none
BUG=b:129159505
TEST=passing CTS sensor run (except test 133 nullptr) with this change

Change-Id: I94b214f021f0b63ff2883e5fe8e32acc83ce208f
Signed-off-by: Jett Rink <jettrink@chromium.org>
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/platform/ec/+/1560390
Tested-by: Alexandru M Stan <amstan@chromium.org>
Reviewed-by: Enrico Granata <egranata@chromium.org>
Reviewed-by: Mathew King <mathewk@chromium.org>
Commit-Queue: ChromeOS CL Exonerator Bot <chromiumos-cl-exonerator@appspot.gserviceaccount.com>

9 files changed, 70 insertions, 33 deletions

diff --git a/chip/ish/heci.c b/chip/ish/heci.c
index b78e522909..9d16b6a74e 100644
--- a/chip/ish/heci.c
+++ b/chip/ish/heci.c
@@ -220,7 +220,8 @@ static void heci_build_fixed_client_header(struct heci_header *hdr,
 	hdr->length |=  (uint16_t)1 << HECI_MSG_CMPL_SHIFT; 
 }
 
-static int heci_send_heci_msg(struct heci_msg *msg)
+static int heci_send_heci_msg_timestamp(struct heci_msg *msg,
+					uint32_t *timestamp)
 {
 	int length, written;
 
@@ -228,7 +229,8 @@ static int heci_send_heci_msg(struct heci_msg *msg)
 		return -1;
 
 	length = sizeof(msg->hdr) + HECI_MSG_LENGTH(msg->hdr.length);
-	written = ipc_write(heci_bus_ctx.ipc_handle, msg, length);
+	written = ipc_write_timestamp(heci_bus_ctx.ipc_handle, msg, length,
+				      timestamp);
 
 	if (written != length) {
 		CPRINTF("%s error : len = %d err = %d\n", __func__,
@@ -239,6 +241,11 @@ static int heci_send_heci_msg(struct heci_msg *msg)
 	return EC_SUCCESS;
 }
 
+static int heci_send_heci_msg(struct heci_msg *msg)
+{
+	return heci_send_heci_msg_timestamp(msg, NULL);
+}
+
 int heci_set_client_data(const heci_handle_t handle, void *data)
 {
 	struct heci_client_context *cli_ctx;
@@ -302,8 +309,8 @@ static int wait_for_flow_ctrl_cred(struct heci_client_connect *connect)
 	return 1;
 }
 
-int heci_send_msg(const heci_handle_t handle, uint8_t *buf,
-		  const size_t buf_size)
+int heci_send_msg_timestamp(const heci_handle_t handle, uint8_t *buf,
+			    const size_t buf_size, uint32_t *timestamp)
 {
 	int buf_offset = 0, ret = 0, remain, payload_size;
 	struct heci_client_connect *connect;
@@ -347,7 +354,7 @@ int heci_send_msg(const heci_handle_t handle, uint8_t *buf,
 
 		memcpy(msg.payload, buf + buf_offset, payload_size);
 
-		heci_send_heci_msg(&msg);
+		heci_send_heci_msg_timestamp(&msg, timestamp);
 
 		remain -= payload_size;
 		buf_offset += payload_size;
@@ -362,6 +369,13 @@ err_locked:
 	return ret;
 }
 
+int heci_send_msg(const heci_handle_t handle, uint8_t *buf,
+		  const size_t buf_size)
+{
+	return heci_send_msg_timestamp(handle, buf, buf_size, NULL);
+}
+
+
 int heci_send_msgs(const heci_handle_t handle,
 		   const struct heci_msg_list *msg_list)
 {
diff --git a/chip/ish/heci_client.h b/chip/ish/heci_client.h
index aab8a928fc..9dca4bff90 100644
--- a/chip/ish/heci_client.h
+++ b/chip/ish/heci_client.h
@@ -90,6 +90,8 @@ void *heci_get_client_data(const heci_handle_t handle);
  */
 int heci_send_msg(const heci_handle_t handle, uint8_t *buf,
 		  const size_t buf_size);
+int heci_send_msg_timestamp(const heci_handle_t handle, uint8_t *buf,
+		  const size_t buf_size, uint32_t *timestamp);
 /*
  * send client msgs(using list of buffer&size).
  * heci_msg_item with size == 0 is not acceptable.
diff --git a/chip/ish/host_command_heci.c b/chip/ish/host_command_heci.c
index 3676451cc9..2de584d6b8 100644
--- a/chip/ish/host_command_heci.c
+++ b/chip/ish/host_command_heci.c
@@ -53,14 +53,21 @@ enum heci_cros_ec_channel {
 static uint8_t response_buffer[IPC_MAX_PAYLOAD_SIZE] __aligned(4);
 static struct host_packet heci_packet;
 
-void heci_send_mkbp_event(void)
+int heci_send_mkbp_event(uint32_t *timestamp)
 {
 	struct cros_ec_ishtp_msg evt;
+	int rv;
 
 	evt.hdr.channel = CROS_MKBP_EVENT;
 	evt.hdr.status = 0;
 
-	heci_send_msg(heci_cros_ec_handle, (uint8_t *)&evt, sizeof(evt));
+	rv = heci_send_msg_timestamp(heci_cros_ec_handle, (uint8_t *)&evt,
+				     sizeof(evt), timestamp);
+	/*
+	 * heci_send_msg_timestamp sends back negative error codes. Change to
+	 * EC style codes
+	 */
+	return rv < 0 ? -rv : EC_SUCCESS;
 }
 
 static void heci_send_hostcmd_response(struct host_packet *pkt)
diff --git a/chip/ish/ipc_heci.c b/chip/ish/ipc_heci.c
index 1d6a59d95b..591e246f81 100644
--- a/chip/ish/ipc_heci.c
+++ b/chip/ish/ipc_heci.c
@@ -31,6 +31,7 @@
 #include "ish_fwst.h"
 #include "queue.h"
 #include "hooks.h"
+#include "hwtimer.h"
 
 #define CPUTS(outstr) cputs(CC_LPC, outstr)
 #define CPRINTS(format, args...) cprints(CC_LPC, format, ## args)
@@ -109,6 +110,7 @@
 
 struct ipc_msg {
 	uint32_t drbl;
+	uint32_t *timestamp_of_outgoing_doorbell;
 	uint8_t payload[IPC_MSG_MAX_SIZE];
 } __packed;
 
@@ -227,9 +229,9 @@ static void write_payload_and_ring_drbl(const struct ipc_if_ctx *ctx,
 	REG32(ctx->out_drbl_reg) = drbl;
 }
 
-
-static int ipc_write_raw(struct ipc_if_ctx *ctx, uint32_t drbl,
-			 const uint8_t *payload, size_t payload_size)
+static int ipc_write_raw_timestamp(struct ipc_if_ctx *ctx, uint32_t drbl,
+				   const uint8_t *payload, size_t payload_size,
+				   uint32_t *timestamp)
 {
 	struct queue *q = &ctx->tx_queue;
 	struct ipc_msg *msg;
@@ -245,6 +247,7 @@ static int ipc_write_raw(struct ipc_if_ctx *ctx, uint32_t drbl,
 			tail = q->state->tail & (q->buffer_units - 1);
 			msg = (struct ipc_msg *)q->buffer + tail;
 			msg->drbl = drbl;
+			msg->timestamp_of_outgoing_doorbell = timestamp;
 			memcpy(msg->payload, payload, payload_size);
 			queue_advance_tail(q, 1);
 		} else {
@@ -260,11 +263,21 @@ static int ipc_write_raw(struct ipc_if_ctx *ctx, uint32_t drbl,
 
 	write_payload_and_ring_drbl(ctx, drbl, payload, payload_size);
 
+	/* We wrote inline, take timestamp now */
+	if (timestamp)
+		*timestamp = __hw_clock_source_read();
+
 write_unlock:
 	mutex_unlock(&ctx->write_lock);
 	return res;
 }
 
+static int ipc_write_raw(struct ipc_if_ctx *ctx, uint32_t drbl,
+			 const uint8_t *payload, size_t payload_size)
+{
+	return ipc_write_raw_timestamp(ctx, drbl, payload, payload_size, NULL);
+}
+
 static int ipc_send_reset_notify(const ipc_handle_t handle)
 {
 	struct ipc_rst_payload *ipc_rst;
@@ -416,6 +429,10 @@ static void handle_busy_clear_interrupt(const uint32_t peer_id)
 		msg = (struct ipc_msg *)(q->buffer + head * q->unit_bytes);
 		write_payload_and_ring_drbl(ctx, msg->drbl, msg->payload,
 					    IPC_DB_MSG_LENGTH(msg->drbl));
+		if (msg->timestamp_of_outgoing_doorbell)
+			*msg->timestamp_of_outgoing_doorbell =
+				__hw_clock_source_read();
+
 		queue_advance_head(q, 1);
 	} else {
 		ctx->is_tx_ipc_busy = 0;
@@ -477,7 +494,8 @@ static void ipc_host2ish_busy_clear_isr(void)
 }
 DECLARE_IRQ(ISH_IPC_ISH2HOST_CLR_IRQ, ipc_host2ish_busy_clear_isr);
 
-int ipc_write(const ipc_handle_t handle, const void *buf, const size_t buf_size)
+int ipc_write_timestamp(const ipc_handle_t handle, const void *buf,
+			const size_t buf_size, uint32_t *timestamp)
 {
 	int ret;
 	struct ipc_if_ctx *ctx;
@@ -526,7 +544,8 @@ int ipc_write(const ipc_handle_t handle, const void *buf, const size_t buf_size)
 		return -EC_ERROR_OVERFLOW;
 	}
 
-	ret = ipc_write_raw(ctx, drbl, payload, payload_size);
+	ret = ipc_write_raw_timestamp(ctx, drbl, payload, payload_size,
+				      timestamp);
 	if (ret)
 		return ret;
 
diff --git a/chip/ish/ipc_heci.h b/chip/ish/ipc_heci.h
index e7238df83d..183e6a2c6b 100644
--- a/chip/ish/ipc_heci.h
+++ b/chip/ish/ipc_heci.h
@@ -77,7 +77,7 @@ int ipc_read(const ipc_handle_t handle, void *buf, const size_t buf_size,
              int timeout_us);
 
 /* Write message to ipc channel. */
-int ipc_write(const ipc_handle_t handle, const void *buf,
-	      const size_t buf_size);
+int ipc_write_timestamp(const ipc_handle_t handle, const void *buf,
+	      const size_t buf_size, uint32_t *timestamp);
 
 #endif /* __IPC_HECI_H */
diff --git a/chip/mt_scp/ipi.c b/chip/mt_scp/ipi.c
index d41b39f4d4..7b42da2423 100644
--- a/chip/mt_scp/ipi.c
+++ b/chip/mt_scp/ipi.c
@@ -28,6 +28,7 @@
 #include "system.h"
 #include "task.h"
 #include "util.h"
+#include "hwtimer.h"
 
 #define CPRINTF(format, args...) cprintf(CC_IPI, format, ##args)
 #define CPRINTS(format, args...) cprints(CC_IPI, format, ##args)
@@ -181,11 +182,18 @@ void ipi_inform_ap(void)
 
 #ifdef HAS_TASK_HOSTCMD
 #if defined(CONFIG_MKBP_USE_CUSTOM)
-void mkbp_set_host_active_via_custom(int active)
+int mkbp_set_host_active_via_custom(int active, uint32_t *timestamp)
 {
 	static const uint8_t hc_evt_obj = HOSTCMD_TYPE_HOSTEVENT;
+
+	/* This should be moved into ipi_send for more accuracy */
+	if (timestamp)
+		*timestamp = __hw_clock_source_read();
+
 	if (active)
-		ipi_send(IPI_HOST_COMMAND, &hc_evt_obj, sizeof(hc_evt_obj), 1);
+		return ipi_send(IPI_HOST_COMMAND, &hc_evt_obj,
+				sizeof(hc_evt_obj), 1);
+	return EC_SUCCESS;
 }
 #endif
 
diff --git a/common/mkbp_event.c b/common/mkbp_event.c
index 5e64183e43..28e6a6fc98 100644
--- a/common/mkbp_event.c
+++ b/common/mkbp_event.c
@@ -106,14 +106,8 @@ static int mkbp_set_host_active_via_event(int active, uint32_t *timestamp)
 #ifdef CONFIG_MKBP_USE_HECI
 static int mkbp_set_host_active_via_heci(int active, uint32_t *timestamp)
 {
-	/*
-	 * TODO change heci_send_mkbp_event declaration. Done in
-	 * child CL to decouple changes.
-	 */
-	if (timestamp)
-		*timestamp = __hw_clock_source_read();
 	if (active)
-		heci_send_mkbp_event();
+		return heci_send_mkbp_event(timestamp);
 	return EC_SUCCESS;
 }
 #endif
@@ -132,14 +126,7 @@ static int mkbp_set_host_active_via_heci(int active, uint32_t *timestamp)
 static int mkbp_set_host_active(int active, uint32_t *timestamp)
 {
 #if defined(CONFIG_MKBP_USE_CUSTOM)
-	/*
-	 * TODO change mkbp_set_host_active_via_custom declaration. Done in
-	 * child CL to decouple changes
-	 */
-	if (timestamp)
-		*timestamp = __hw_clock_source_read();
-	mkbp_set_host_active_via_custom(active);
-	return EC_SUCCESS;
+	return mkbp_set_host_active_via_custom(active, timestamp);
 #elif defined(CONFIG_MKBP_USE_HOST_EVENT)
 	return mkbp_set_host_active_via_event(active, timestamp);
 #elif defined(CONFIG_MKBP_USE_GPIO)
diff --git a/include/host_command_heci.h b/include/host_command_heci.h
index af85178e8a..1dcb054ff6 100644
--- a/include/host_command_heci.h
+++ b/include/host_command_heci.h
@@ -7,6 +7,6 @@
 #define __HOST_COMMAND_HECI_H
 
 /* send an event message to the ap */
-void heci_send_mkbp_event(void);
+int heci_send_mkbp_event(uint32_t *timestamp);
 
 #endif /* __HOST_COMMAND_HECI_H */
diff --git a/include/mkbp_event.h b/include/mkbp_event.h
index c451c53673..5bfe7ac505 100644
--- a/include/mkbp_event.h
+++ b/include/mkbp_event.h
@@ -33,7 +33,7 @@ int mkbp_send_event(uint8_t event_type);
  *
  * This can be used if a board has a custom method.
  */
-void mkbp_set_host_active_via_custom(int active);
+int mkbp_set_host_active_via_custom(int active, uint32_t *timestamp);
 
 /*
  * The struct to store the event source definition.  The get_data routine is