From a52503dd1d79e5bcb6c64f339c0c47d44fcb8ab3 Mon Sep 17 00:00:00 2001
From: Harald Welte <laforge@osmocom.org>
Date: Mon, 11 Sep 2023 12:57:02 +0200
Subject: [PATCH] tusb_cardem: Introduce LOGBEP macro

---
 composite/tusb_cardem.c | 21 ++++++++++++++++++---
 1 file changed, 18 insertions(+), 3 deletions(-)

diff --git a/composite/tusb_cardem.c b/composite/tusb_cardem.c
index 3591325..1e79495 100644
--- a/composite/tusb_cardem.c
+++ b/composite/tusb_cardem.c
@@ -64,6 +64,9 @@ void bep_msgb_free(struct msgb *msg)
 	msgb_free(msg);
 }
 
+#define LOGBEP(bep, fmt, args ...) \
+	printf("%s(%02x): " fmt, __func__, (bep)->ep, ## args)
+
 
 /* IN/IRQ EP: dequeue next pending message and send it to host */
 int bep_refill_to_host(struct usb_buffered_ep *bep)
@@ -71,17 +74,21 @@ int bep_refill_to_host(struct usb_buffered_ep *bep)
 	unsigned long x;
 	const uint8_t rhport = 0;
 
-	if (usbd_edpt_busy(rhport, bep->ep))
+	if (usbd_edpt_busy(rhport, bep->ep)) {
+		LOGBEP(bep, "skipping: edpt_busy\r\n");
 		return 0;
+	}
 
 	local_irq_save(x);
 	if (bep->msg_in_progress) {
 		local_irq_restore(x);
+		LOGBEP(bep, "skipping: msg_in_progress\r\n");
 		return 0;
 	}
 
 	if (llist_empty(&bep->queue)) {
 		local_irq_restore(x);
+		LOGBEP(bep, "skipping: queue empty\r\n");
 		return 0;
 	}
 
@@ -90,6 +97,8 @@ int bep_refill_to_host(struct usb_buffered_ep *bep)
 
 	TU_VERIFY(usbd_edpt_xfer(rhport, bep->ep, msgb_data(bep->msg_in_progress),
 				 msgb_length(bep->msg_in_progress)));
+
+	LOGBEP(bep, "success (msg=%p, data=%p/%u)!\r\n", bep->msg_in_progress, msgb_data(bep->msg_in_progress), msgb_length(bep->msg_in_progress));
 	return 1;
 }
 
@@ -103,6 +112,7 @@ struct msgb *bep_get_completed(struct usb_buffered_ep *bep)
 	msg = bep->msg_in_progress;
 	bep->msg_in_progress = NULL;
 	local_irq_restore(x);
+	LOGBEP(bep, "(msg=%p)\r\n", msg);
 
 	return msg;
 }
@@ -111,6 +121,7 @@ struct msgb *bep_get_completed(struct usb_buffered_ep *bep)
 void bep_complete_in_progress(struct usb_buffered_ep *bep)
 {
 	struct msgb *msg = bep_get_completed(bep);
+	LOGBEP(bep, "(msg=%p)\r\n", msg);
 	bep_msgb_free(msg);
 }
 
@@ -138,6 +149,7 @@ int bep_enqueue_msgb(struct msgb *msg)
 		bep_msgb_free(evict);
 	}
 
+	LOGBEP(ep, "(msg=%p)\r\n", msg);
 	msgb_enqueue_count(&ep->queue, msg, &ep->queue_len);
 	return 0;
 }
@@ -278,6 +290,7 @@ static uint16_t cardemd_open(uint8_t rhport, tusb_desc_interface_t const *itf_de
 			tusb_desc_endpoint_t const * desc_ep = (tusb_desc_endpoint_t const *) p_desc;
 			TU_ASSERT(TUSB_DESC_ENDPOINT == desc_ep->bDescriptorType);
 			/* open each endpoint */
+			printf("opening EP 0x%02x\r\n", desc_ep->bEndpointAddress);
 			TU_ASSERT(usbd_edpt_open(rhport, desc_ep));
 
 			uint8_t ep_nr = tu_edpt_number(desc_ep->bEndpointAddress);
@@ -358,7 +371,7 @@ static void stp_tx_error(struct usb_buffered_ep *bep, uint8_t seq_nr, uint8_t sl
 	struct msgb *msg = bep_msgb_alloc(bep);
 	struct cardemu_usb_msg_error *err;
 
-	printf("%s(slot_nr=%u, severity=%u, subsys=%u, code=0x%04x, msg=%s\r\n", __func__,
+	LOGBEP(bep, "(slot_nr=%u, severity=%u, subsys=%u, code=0x%04x, msg=%s)\r\n",
 		slot_nr, severity, subsystem, code, errmsg);
 
 	if (!msg)
@@ -418,7 +431,7 @@ static void my_ep_out_handler(struct msgb *msg, struct usb_buffered_ep *bep)
 		goto out;
 	}
 
-	printf("%s(slot_nr=%u, class=%u, msg_type=%u, seq_nr=%u, len=%u)\r\n", __func__,
+	LOGBEP(bep, "(slot_nr=%u, class=%u, msg_type=%u, seq_nr=%u, len=%u)\r\n", __func__,
 		smh->slot_nr, smh->msg_class, smh->msg_type, smh->seq_nr, smh->msg_len);
 
 	switch (smh->msg_class) {
@@ -442,6 +455,8 @@ static bool cardemd_xfer_cb(uint8_t __unused rhport, uint8_t ep_addr, xfer_resul
 {
 	struct msgb *msg;
 	uint8_t epidx;
+	printf("%s(ep=0x%02x, result=%u, bytes=%u\r\n", __func__, ep_addr, result, xferred_bytes);
+
 	struct usb_buffered_ep *bep = bep_for_epaddr(ep_addr, &epidx);
 	if (!bep)
 		return false;