From 313fddf7228d2aacd45bb276845ef41d80f2dea6 Mon Sep 17 00:00:00 2001 From: "Sergio R. Caprile" Date: Wed, 7 Sep 2022 10:11:07 -0300 Subject: [PATCH] Add rudimentary queue profiler ETH IRQ and mip_poll() can both write to the queue, so if a memcpy() is interrupted we might see some weird records. --- mip/driver_stm32.c | 3 +++ mip/mip.c | 61 +++++++++++++++++++++++++++++++++++++++++++ mip/mip.h | 8 ++++++ mongoose.c | 64 ++++++++++++++++++++++++++++++++++++++++++++++ mongoose.h | 8 ++++++ 5 files changed, 144 insertions(+) diff --git a/mip/driver_stm32.c b/mip/driver_stm32.c index 725cd0c4..11d49151 100644 --- a/mip/driver_stm32.c +++ b/mip/driver_stm32.c @@ -139,6 +139,9 @@ static bool mip_driver_stm32_up(void *userdata) { void ETH_IRQHandler(void); void ETH_IRQHandler(void) { +#ifdef MIP_QPROFILE + qp_mark(QP_IRQTRIGGERED, 0); +#endif volatile uint32_t sr = ETH->DMASR; if (sr & BIT(6)) { // Frame received, loop for (uint32_t i = 0; i < ETH_DESC_CNT; i++) { diff --git a/mip/mip.c b/mip/mip.c index 150847d0..1fcda167 100644 --- a/mip/mip.c +++ b/mip/mip.c @@ -716,7 +716,13 @@ static void mip_poll(struct mip_if *ifp, uint64_t uptime_ms) { : ifp->driver->rx(ifp->rx.buf, ifp->rx.len, ifp->driver_data); if (len == 0) break; +#ifdef MIP_QPROFILE + qp_mark(QP_FRAMEPOPPED, (int) len); +#endif mip_rx(ifp, ifp->rx.buf, len); +#ifdef MIP_QPROFILE + qp_mark(QP_FRAMEDONE, (int) len); +#endif } // Process timeouts @@ -735,6 +741,9 @@ static void mip_poll(struct mip_if *ifp, uint64_t uptime_ms) { s->ttype = 1; } } +#ifdef MIP_QPROFILE + qp_log(); +#endif } // This function executes in interrupt context, thus it should copy data @@ -742,7 +751,11 @@ static void mip_poll(struct mip_if *ifp, uint64_t uptime_ms) { // our lock-free queue with preallocated buffer to copy data and return asap static void on_rx(void *buf, size_t len, void *userdata) { struct mip_if *ifp = (struct mip_if *) userdata; +#ifndef MIP_QPROFILE if (!q_write(&ifp->queue, buf, len)) MG_ERROR(("dropped %d", (int) len)); +#else + qp_mark(q_write(&ifp->queue, buf, len) ? QP_FRAMEPUSHED:QP_FRAMEDROPPED, (int) len); +#endif } void mip_init(struct mg_mgr *mgr, struct mip_cfg *ipcfg, @@ -768,6 +781,9 @@ void mip_init(struct mg_mgr *mgr, struct mip_cfg *ipcfg, if (driver->setrx) driver->setrx(on_rx, ifp); mgr->priv = ifp; mgr->extraconnsize = sizeof(struct connstate); +#ifdef MIP_QPROFILE + qp_init(); +#endif } } @@ -865,4 +881,49 @@ bool mg_send(struct mg_connection *c, const void *buf, size_t len) { } return res; } + + +#ifdef MIP_QPROFILE + +#pragma pack(push, 1) +struct qpentry { + uint64_t timestamp; + uint16_t type; + uint16_t len; +}; +#pragma pack(pop) + +static struct queue qp; + +void qp_mark(unsigned int type, int len) +{ +static bool ovf = false; +struct qpentry e = { + .timestamp = mg_millis(), + .type = ovf ? (uint16_t)QP_QUEUEOVF : (uint16_t)type, + .len = (uint16_t) len +}; + + ovf = !q_write(&qp, &e, sizeof(e)); +} + +void qp_log(void) +{ +struct qpentry e; + + for(int i=0 ; i < 10 ; i++) + if(q_read(&qp, &e)) MG_INFO(("%llu, %u, %u", e.timestamp, e.type, e.len)); + else break; +} + +void qp_init(void) +{ +unsigned int qlen = 500 * (sizeof(size_t) + sizeof(struct qpentry)); + + qp.buf = calloc(1, qlen); + qp.len = qlen; +// THERE IS NO FREE +} +#endif // MIP_QPROFILE + #endif // MG_ENABLE_MIP diff --git a/mip/mip.h b/mip/mip.h index a25d3d79..0748cc0a 100644 --- a/mip/mip.h +++ b/mip/mip.h @@ -30,3 +30,11 @@ struct mip_spi { void (*end)(void *); // SPI end: slave select high uint8_t (*txn)(void *, uint8_t); // SPI transaction: write 1 byte, read reply }; + +#ifdef MIP_QPROFILE +enum {QP_IRQTRIGGERED=0, QP_FRAMEPUSHED, QP_FRAMEPOPPED, QP_FRAMEDONE, QP_FRAMEDROPPED, QP_QUEUEOVF}; + +void qp_mark(unsigned int type, int len); +void qp_log(void); +void qp_init(void); +#endif diff --git a/mongoose.c b/mongoose.c index 85951302..34191ec2 100644 --- a/mongoose.c +++ b/mongoose.c @@ -6114,6 +6114,9 @@ static bool mip_driver_stm32_up(void *userdata) { void ETH_IRQHandler(void); void ETH_IRQHandler(void) { +#ifdef MIP_QPROFILE + qp_mark(QP_IRQTRIGGERED, 0); +#endif volatile uint32_t sr = ETH->DMASR; if (sr & BIT(6)) { // Frame received, loop for (uint32_t i = 0; i < ETH_DESC_CNT; i++) { @@ -7004,7 +7007,13 @@ static void mip_poll(struct mip_if *ifp, uint64_t uptime_ms) { : ifp->driver->rx(ifp->rx.buf, ifp->rx.len, ifp->driver_data); if (len == 0) break; +#ifdef MIP_QPROFILE + qp_mark(QP_FRAMEPOPPED, (int) len); +#endif mip_rx(ifp, ifp->rx.buf, len); +#ifdef MIP_QPROFILE + qp_mark(QP_FRAMEDONE, (int) len); +#endif } // Process timeouts @@ -7023,6 +7032,9 @@ static void mip_poll(struct mip_if *ifp, uint64_t uptime_ms) { s->ttype = 1; } } +#ifdef MIP_QPROFILE + qp_log(); +#endif } // This function executes in interrupt context, thus it should copy data @@ -7030,7 +7042,11 @@ static void mip_poll(struct mip_if *ifp, uint64_t uptime_ms) { // our lock-free queue with preallocated buffer to copy data and return asap static void on_rx(void *buf, size_t len, void *userdata) { struct mip_if *ifp = (struct mip_if *) userdata; +#ifndef MIP_QPROFILE if (!q_write(&ifp->queue, buf, len)) MG_ERROR(("dropped %d", (int) len)); +#else + qp_mark(q_write(&ifp->queue, buf, len) ? QP_FRAMEPUSHED:QP_FRAMEDROPPED, (int) len); +#endif } void mip_init(struct mg_mgr *mgr, struct mip_cfg *ipcfg, @@ -7056,6 +7072,9 @@ void mip_init(struct mg_mgr *mgr, struct mip_cfg *ipcfg, if (driver->setrx) driver->setrx(on_rx, ifp); mgr->priv = ifp; mgr->extraconnsize = sizeof(struct connstate); +#ifdef MIP_QPROFILE + qp_init(); +#endif } } @@ -7153,4 +7172,49 @@ bool mg_send(struct mg_connection *c, const void *buf, size_t len) { } return res; } + + +#ifdef MIP_QPROFILE + +#pragma pack(push, 1) +struct qpentry { + uint64_t timestamp; + uint16_t type; + uint16_t len; +}; +#pragma pack(pop) + +static struct queue qp; + +void qp_mark(unsigned int type, int len) +{ +static bool ovf = false; +struct qpentry e = { + .timestamp = mg_millis(), + .type = ovf ? (uint16_t)QP_QUEUEOVF : (uint16_t)type, + .len = (uint16_t) len +}; + + ovf = !q_write(&qp, &e, sizeof(e)); +} + +void qp_log(void) +{ +struct qpentry e; + + for(int i=0 ; i < 10 ; i++) + if(q_read(&qp, &e)) MG_INFO(("%llu, %u, %u", e.timestamp, e.type, e.len)); + else break; +} + +void qp_init(void) +{ +unsigned int qlen = 500 * (sizeof(size_t) + sizeof(struct qpentry)); + + qp.buf = calloc(1, qlen); + qp.len = qlen; +// THERE IS NO FREE +} +#endif // MIP_QPROFILE + #endif // MG_ENABLE_MIP diff --git a/mongoose.h b/mongoose.h index 0ef83ce2..c301588d 100644 --- a/mongoose.h +++ b/mongoose.h @@ -1450,6 +1450,14 @@ struct mip_spi { uint8_t (*txn)(void *, uint8_t); // SPI transaction: write 1 byte, read reply }; +#ifdef MIP_QPROFILE +enum {QP_IRQTRIGGERED=0, QP_FRAMEPUSHED, QP_FRAMEPOPPED, QP_FRAMEDONE, QP_FRAMEDROPPED, QP_QUEUEOVF}; + +void qp_mark(unsigned int type, int len); +void qp_log(void); +void qp_init(void); +#endif + #ifdef __cplusplus } #endif