Add profiling capability

Makefile

@@ -177,8 +177,7 @@ mongoose.c: Makefile $(wildcard src/*.c) $(wildcard src/drivers/*.c)
 	(cat src/license.h; echo; echo '#include "mongoose.h"' ; (for F in src/*.c src/drivers/*.c ; do echo; echo '#ifdef MG_ENABLE_LINES'; echo "#line 1 \"$$F\""; echo '#endif'; cat $$F | sed -e 's,#include ".*,,'; done))> $@
 
 mongoose.h: $(HDRS) Makefile
-	(cat src/license.h; echo; echo '#ifndef MONGOOSE_H'; echo '#define MONGOOSE_H'; echo; cat src/version.h ; echo; echo '#ifdef __cplusplus'; echo 'extern "C" {'; echo '#endif'; cat src/arch.h src/arch_*.h src/net_ft.h src/net_lwip.h src/net_rl.h src/config.h src/str.h src/queue.h src/fmt.h src/printf.h src/log.h src/timer.h src/fs.h src/util.h src/url.h src/iobuf.h src/base64.h src/md5.h src/sha1.h src/event.h src/net.h src/http.h src/ssi.h src/tls.h src/tls_mbed.h src/tls_openssl.h src/ws.h src/sntp.h src/mqtt.h src/dns.h src/json.h src/rpc.h src/ota.h src/device.h src/net_builtin.h src/drivers/*.h | sed -e '/keep/! s,#include ".*,,' -e 's,^#pragma once,,'; echo; echo '#ifdef __cplusplus'; echo '}'; echo '#endif'; echo '#endif  // MONGOOSE_H')> $@
-
+	(cat src/license.h; echo; echo '#ifndef MONGOOSE_H'; echo '#define MONGOOSE_H'; echo; cat src/version.h ; echo; echo '#ifdef __cplusplus'; echo 'extern "C" {'; echo '#endif'; cat src/arch.h src/arch_*.h src/net_ft.h src/net_lwip.h src/net_rl.h src/config.h src/str.h src/queue.h src/fmt.h src/printf.h src/log.h src/timer.h src/fs.h src/util.h src/url.h src/iobuf.h src/base64.h src/md5.h src/sha1.h src/event.h src/net.h src/profile.h src/http.h src/ssi.h src/tls.h src/tls_mbed.h src/tls_openssl.h src/ws.h src/sntp.h src/mqtt.h src/dns.h src/json.h src/rpc.h src/ota.h src/device.h src/net_builtin.h src/drivers/*.h | sed -e '/keep/! s,#include ".*,,' -e 's,^#pragma once,,'; echo; echo '#ifdef __cplusplus'; echo '}'; echo '#endif'; echo '#endif  // MONGOOSE_H')> $@
 
 clean: clean_examples clean_embedded
 	rm -rf $(PROG) *.exe *.o *.dSYM *_test* ut fuzzer *.gcov *.gcno *.gcda *.obj *.exe *.ilk *.pdb slow-unit* _CL_* infer-out data.txt crash-* test/packed_fs.c pack

examples/mqtt-dashboard/device/main.c

@@ -12,13 +12,13 @@ static void signal_handler(int signo) {
 // Mocked device pins
 static bool s_pins[100];
 
-void gpio_write(int pin, bool status) {
+void hal_gpio_write(int pin, bool status) {
   if (pin >= 0 && pin <= (int) (sizeof(s_pins) / sizeof(s_pins[0]))) {
     s_pins[pin] = status;
   }
 }
 
-bool gpio_read(int pin) {
+bool hal_gpio_read(int pin) {
   return (pin >= 0 && pin <= (int) (sizeof(s_pins) / sizeof(s_pins[0])))
              ? s_pins[pin]
              : false;

examples/mqtt-dashboard/device/net.c

@@ -46,7 +46,7 @@ static void publish_status(struct mg_connection *c) {
   struct mg_mqtt_opts pub_opts;
   memset(&pub_opts, 0, sizeof(pub_opts));
   pub_opts.topic = pubt;
-  s_device_config.led_status = gpio_read(s_device_config.led_pin);
+  s_device_config.led_status = hal_gpio_read(s_device_config.led_pin);
   char *device_status_json = mg_mprintf(
       "{%m:%m,%m:{%m:%m,%m:%s,%m:%hhu,%m:%hhu,%m:%hhu,%m:%M,%m:%M}}",
       MG_ESC("method"), MG_ESC("status.notify"), MG_ESC("params"),
@@ -114,7 +114,7 @@ static void rpc_config_set(struct mg_rpc_req *r) {
   if (tmp_pin > 0) s_device_config.led_pin = tmp_pin;
 
   if (tmp_pin > 0 && ok) {
-    gpio_write(s_device_config.led_pin, s_device_config.led_status);
+    hal_gpio_write(s_device_config.led_pin, s_device_config.led_status);
   }
 
   mg_rpc_ok(r, "%m", MG_ESC("ok"));
@@ -219,7 +219,7 @@ static void timer_fn(void *arg) {
                                 .qos = s_qos,
                                 .topic = mg_str(status_topic),
                                 .version = 4,
-                                .keepalive = KEEP_ALIVE_INTERVAL,
+                                .keepalive = MQTT_KEEP_ALIVE_INTERVAL,
                                 .retain = true,
                                 .message = mg_str(msg)};
     s_conn = mg_mqtt_connect(mgr, g_url, &opts, fn, NULL);
@@ -234,9 +234,9 @@ static void timer_keepalive(void *arg) {
 }
 
 void web_init(struct mg_mgr *mgr) {
-  int pingreq_interval_ms = KEEP_ALIVE_INTERVAL * 1000 - 500;
+  int pingreq_interval_ms = MQTT_KEEP_ALIVE_INTERVAL * 1000 - 500;
   if (!g_device_id) generate_device_id();
-  if (!g_root_topic) g_root_topic = DEFAULT_ROOT_TOPIC;
+  if (!g_root_topic) g_root_topic = MQTT_ROOT_TOPIC;
   s_device_config.log_level = (uint8_t) mg_log_level;
 
   // Configure JSON-RPC functions we're going to handle

examples/mqtt-dashboard/device/net.h

@@ -13,10 +13,9 @@ extern "C" {
 #endif
 
 #define DEVICE_ID_LEN 10
-#define ROOT_TOPIC_LEN 30
-#define KEEP_ALIVE_INTERVAL 60
+#define MQTT_KEEP_ALIVE_INTERVAL 60
 #define MQTT_SERVER_URL "mqtt://broker.hivemq.com:1883"
-#define DEFAULT_ROOT_TOPIC "topic_mg_device"
+#define MQTT_ROOT_TOPIC "topic_mg_device"
 
 extern char *g_url;
 extern char *g_device_id;
@@ -25,8 +24,8 @@ extern char *g_root_topic;
 void web_init(struct mg_mgr *mgr);
 void web_destroy();
 
-void gpio_write(int pin, bool status);
-bool gpio_read(int pin);
+void hal_gpio_write(int pin, bool status);
+bool hal_gpio_read(int pin);
 
 #ifdef __cplusplus
 }

examples/stm32/nucleo-h723zg-make-baremetal-builtin/main.c

@@ -23,6 +23,14 @@ void mg_random(void *buf, size_t len) {  // Use on-board RNG
   }
 }
 
+void hal_gpio_write(int pin, bool status) {  // For MQTT dashboard HAL
+  gpio_write((uint16_t) pin, status);
+}
+
+bool hal_gpio_read(int pin) {  // For MQTT dashboard HAL
+  return gpio_read((uint16_t) pin);
+}
+
 static void timer_fn(void *arg) {
   gpio_toggle(LED);                                      // Blink LED
   struct mg_tcpip_if *ifp = arg;                         // And show
@@ -37,13 +45,14 @@ int main(void) {
   uart_init(UART_DEBUG, 115200);  // Initialise debug printf
   ethernet_init();                // Initialise ethernet pins
 
-  #ifdef MQTT_DASHBOARD
-    // User can customise the MQTT url, device ID or the root topic below
-  #define DEVICE_ID "H723ZG"
-    g_url = MQTT_SERVER_URL;
-    g_device_id = DEVICE_ID;
-    g_root_topic = DEFAULT_ROOT_TOPIC;
-  #endif
+#ifdef MQTT_DASHBOARD
+                    // User can customise the MQTT url, device ID or the root
+                    // topic below
+#define DEVICE_ID "H723ZG"
+  g_url = MQTT_SERVER_URL;
+  g_device_id = DEVICE_ID;
+  g_root_topic = DEFAULT_ROOT_TOPIC;
+#endif
 
   MG_INFO(("Starting, CPU freq %g MHz", (double) SystemCoreClock / 1000000));
 

mongoose.c

@@ -987,6 +987,17 @@ void mg_resolve(struct mg_connection *c, const char *url) {
 
 
 void mg_call(struct mg_connection *c, int ev, void *ev_data) {
+#if MG_ENABLE_PROFILE
+  const char *names[] = {
+      "EV_ERROR",    "EV_OPEN",      "EV_POLL",      "EV_RESOLVE",
+      "EV_CONNECT",  "EV_ACCEPT",    "EV_TLS_HS",    "EV_READ",
+      "EV_WRITE",    "EV_CLOSE",     "EV_HTTP_MSG",  "EV_HTTP_CHUNK",
+      "EV_WS_OPEN",  "EV_WS_MSG",    "EV_WS_CTL",    "EV_MQTT_CMD",
+      "EV_MQTT_MSG", "EV_MQTT_OPEN", "EV_SNTP_TIME", "EV_USER"};
+  if (ev != MG_EV_POLL && ev < (int) (sizeof(names) / sizeof(names[0]))) {
+    MG_PROF_ADD(c, names[ev]);
+  }
+#endif
   // Run user-defined handler first, in order to give it an ability
   // to intercept processing (e.g. clean input buffer) before the
   // protocol handler kicks in
@@ -4308,6 +4319,7 @@ struct mg_connection *mg_alloc_conn(struct mg_mgr *mgr) {
     c->mgr = mgr;
     c->send.align = c->recv.align = MG_IO_SIZE;
     c->id = ++mgr->nextid;
+    MG_PROF_INIT(c);
   }
   return c;
 }
@@ -4321,6 +4333,8 @@ void mg_close_conn(struct mg_connection *c) {
   // before we deallocate received data, see #1331
   mg_call(c, MG_EV_CLOSE, NULL);
   MG_DEBUG(("%lu %ld closed", c->id, c->fd));
+  MG_PROF_DUMP(c);
+  MG_PROF_FREE(c);
 
   mg_tls_free(c);
   mg_iobuf_free(&c->recv);
@@ -4357,6 +4371,7 @@ struct mg_connection *mg_listen(struct mg_mgr *mgr, const char *url,
     MG_ERROR(("OOM %s", url));
   } else if (!mg_open_listener(c, url)) {
     MG_ERROR(("Failed: %s, errno %d", url, errno));
+    MG_PROF_FREE(c);
     free(c);
     c = NULL;
   } else {

mongoose.h

@@ -820,6 +820,10 @@ struct timeval {
 #define MG_EPOLL_MOD(c, wr)
 #endif
 
+#ifndef MG_ENABLE_PROFILE
+#define MG_ENABLE_PROFILE 0
+#endif
+
 
 
 
@@ -1242,6 +1246,7 @@ struct mg_connection {
   unsigned long id;            // Auto-incrementing unique connection ID
   struct mg_iobuf recv;        // Incoming data
   struct mg_iobuf send;        // Outgoing data
+  struct mg_iobuf prof;        // Profile data enabled by MG_ENABLE_PROFILE
   mg_event_handler_t fn;       // User-specified event handler function
   void *fn_data;               // User-specified function parameter
   mg_event_handler_t pfn;      // Protocol-specific handler function
@@ -1300,6 +1305,50 @@ long mg_io_recv(struct mg_connection *c, void *buf, size_t len);
 
 
 
+#if MG_ENABLE_PROFILE
+struct mg_profitem {
+  const char *name;
+  uint32_t timestamp;
+};
+
+#define MG_PROF_ADD(c, name_)                                          \
+  do {                                                                 \
+    struct mg_iobuf *io = &c->prof;                                    \
+    struct mg_profitem *first = (struct mg_profitem *) io->buf;        \
+    struct mg_profitem item = {name_, (uint32_t) mg_millis()};         \
+    if (io->len >= sizeof(*first)) item.timestamp -= first->timestamp; \
+    mg_iobuf_add(io, io->len, &item, sizeof(item));                    \
+  } while (0)
+
+#define MG_PROF_INIT(c)                \
+  do {                                 \
+    mg_iobuf_init(&(c)->prof, 0, 256); \
+    MG_PROF_ADD((c), "init");          \
+  } while (0)
+
+#define MG_PROF_FREE(c) mg_iobuf_free(&(c)->prof)
+
+#define MG_PROF_DUMP(c)                                               \
+  do {                                                                \
+    struct mg_iobuf *io = &c->prof;                                   \
+    struct mg_profitem *p = (struct mg_profitem *) io->buf;           \
+    struct mg_profitem *e = &p[io->len / sizeof(*p)];                 \
+    MG_INFO(("%lu profile:", c->id));                                 \
+    while (p < e) {                                                   \
+      MG_INFO(("%5lx %s", (unsigned long) p->timestamp, p->name)); \
+      p++;                                                            \
+    }                                                                 \
+  } while (0)
+
+#else
+#define MG_PROF_INIT(c)
+#define MG_PROF_FREE(c)
+#define MG_PROF_ADD(c, name)
+#define MG_PROF_DUMP(c)
+#endif
+
+
+
 
 
 

src/arch_zephyr.h

@@ -22,8 +22,15 @@
 #define strdup(s) ((char *) mg_strdup(mg_str(s)).ptr)
 #endif
 #define strerror(x) zsock_gai_strerror(x)
+
+#ifndef FD_CLOEXEC
 #define FD_CLOEXEC 0
+#endif
+
+#ifndef F_SETFD
 #define F_SETFD 0
+#endif
+
 #define MG_ENABLE_SSI 0
 
 int rand(void);

src/config.h

@@ -153,3 +153,7 @@
 #define MG_EPOLL_ADD(c)
 #define MG_EPOLL_MOD(c, wr)
 #endif
+
+#ifndef MG_ENABLE_PROFILE
+#define MG_ENABLE_PROFILE 0
+#endif

src/event.c

@@ -4,6 +4,17 @@
 #include "printf.h"
 
 void mg_call(struct mg_connection *c, int ev, void *ev_data) {
+#if MG_ENABLE_PROFILE
+  const char *names[] = {
+      "EV_ERROR",    "EV_OPEN",      "EV_POLL",      "EV_RESOLVE",
+      "EV_CONNECT",  "EV_ACCEPT",    "EV_TLS_HS",    "EV_READ",
+      "EV_WRITE",    "EV_CLOSE",     "EV_HTTP_MSG",  "EV_HTTP_CHUNK",
+      "EV_WS_OPEN",  "EV_WS_MSG",    "EV_WS_CTL",    "EV_MQTT_CMD",
+      "EV_MQTT_MSG", "EV_MQTT_OPEN", "EV_SNTP_TIME", "EV_USER"};
+  if (ev != MG_EV_POLL && ev < (int) (sizeof(names) / sizeof(names[0]))) {
+    MG_PROF_ADD(c, names[ev]);
+  }
+#endif
   // Run user-defined handler first, in order to give it an ability
   // to intercept processing (e.g. clean input buffer) before the
   // protocol handler kicks in

src/net.c

@@ -3,6 +3,7 @@
 #include "log.h"
 #include "net.h"
 #include "printf.h"
+#include "profile.h"
 #include "timer.h"
 #include "tls.h"
 
@@ -132,6 +133,7 @@ struct mg_connection *mg_alloc_conn(struct mg_mgr *mgr) {
     c->mgr = mgr;
     c->send.align = c->recv.align = MG_IO_SIZE;
     c->id = ++mgr->nextid;
+    MG_PROF_INIT(c);
   }
   return c;
 }
@@ -145,6 +147,8 @@ void mg_close_conn(struct mg_connection *c) {
   // before we deallocate received data, see #1331
   mg_call(c, MG_EV_CLOSE, NULL);
   MG_DEBUG(("%lu %ld closed", c->id, c->fd));
+  MG_PROF_DUMP(c);
+  MG_PROF_FREE(c);
 
   mg_tls_free(c);
   mg_iobuf_free(&c->recv);
@@ -181,6 +185,7 @@ struct mg_connection *mg_listen(struct mg_mgr *mgr, const char *url,
     MG_ERROR(("OOM %s", url));
   } else if (!mg_open_listener(c, url)) {
     MG_ERROR(("Failed: %s, errno %d", url, errno));
+    MG_PROF_FREE(c);
     free(c);
     c = NULL;
   } else {

src/net.h

@@ -49,6 +49,7 @@ struct mg_connection {
   unsigned long id;            // Auto-incrementing unique connection ID
   struct mg_iobuf recv;        // Incoming data
   struct mg_iobuf send;        // Outgoing data
+  struct mg_iobuf prof;        // Profile data enabled by MG_ENABLE_PROFILE
   mg_event_handler_t fn;       // User-specified event handler function
   void *fn_data;               // User-specified function parameter
   mg_event_handler_t pfn;      // Protocol-specific handler function

src/profile.h

@@ -0,0 +1,44 @@
+#pragma once
+#include "iobuf.h"
+
+#if MG_ENABLE_PROFILE
+struct mg_profitem {
+  const char *name;
+  uint32_t timestamp;
+};
+
+#define MG_PROF_ADD(c, name_)                                          \
+  do {                                                                 \
+    struct mg_iobuf *io = &c->prof;                                    \
+    struct mg_profitem *first = (struct mg_profitem *) io->buf;        \
+    struct mg_profitem item = {name_, (uint32_t) mg_millis()};         \
+    if (io->len >= sizeof(*first)) item.timestamp -= first->timestamp; \
+    mg_iobuf_add(io, io->len, &item, sizeof(item));                    \
+  } while (0)
+
+#define MG_PROF_INIT(c)                \
+  do {                                 \
+    mg_iobuf_init(&(c)->prof, 0, 256); \
+    MG_PROF_ADD((c), "init");          \
+  } while (0)
+
+#define MG_PROF_FREE(c) mg_iobuf_free(&(c)->prof)
+
+#define MG_PROF_DUMP(c)                                               \
+  do {                                                                \
+    struct mg_iobuf *io = &c->prof;                                   \
+    struct mg_profitem *p = (struct mg_profitem *) io->buf;           \
+    struct mg_profitem *e = &p[io->len / sizeof(*p)];                 \
+    MG_INFO(("%lu profile:", c->id));                                 \
+    while (p < e) {                                                   \
+      MG_INFO(("%5lx %s", (unsigned long) p->timestamp, p->name)); \
+      p++;                                                            \
+    }                                                                 \
+  } while (0)
+
+#else
+#define MG_PROF_INIT(c)
+#define MG_PROF_FREE(c)
+#define MG_PROF_ADD(c, name)
+#define MG_PROF_DUMP(c)
+#endif

test/unit_test.c

@@ -335,8 +335,13 @@ static void test_iobuf(void) {
   ASSERT(memcmp(io.buf, "xhi!", 3) == 0);
   mg_iobuf_del(&io, 10, 100);
   ASSERT(io.buf != NULL && io.size == 10 && io.len == 4);
-  ASSERT(memcmp(io.buf, "xhi!", 3) == 0);
-  free(io.buf);
+  ASSERT(memcmp(io.buf, "xhi!", io.len) == 0);
+  mg_iobuf_add(&io, io.len, "123456", 6);
+  ASSERT(io.buf != NULL && io.size == 10 && io.len == 10);
+  mg_iobuf_add(&io, io.len, "a", 1);
+  ASSERT(io.buf != NULL && io.size == 20 && io.len == 11);
+  ASSERT(memcmp(io.buf, "xhi!123456a", io.len) == 0);
+  mg_iobuf_free(&io);
 }
 
 static void sntp_cb(struct mg_connection *c, int ev, void *evd, void *fnd) {