add skynet.stat() to get cpu cost and message count

lualib-src/lua-skynet.c

@@ -126,15 +126,30 @@ lintcommand(lua_State *L) {
 	const char * parm = NULL;
 	char tmp[64];	// for integer parm
 	if (lua_gettop(L) == 2) {
-		int32_t n = (int32_t)luaL_checkinteger(L,2);
-		sprintf(tmp, "%d", n);
-		parm = tmp;
+		if (lua_isnumber(L, 2)) {
+			int32_t n = (int32_t)luaL_checkinteger(L,2);
+			sprintf(tmp, "%d", n);
+			parm = tmp;
+		} else {
+			parm = luaL_checkstring(L,2);
+		}
 	}
 
 	result = skynet_command(context, cmd, parm);
 	if (result) {
-		lua_Integer r = strtoll(result, NULL, 0);
-		lua_pushinteger(L, r);
+		char *endptr = NULL; 
+		lua_Integer r = strtoll(result, &endptr, 0);
+		if (endptr == NULL || *endptr != '\0') {
+			// may be real number
+			double n = strtod(result, &endptr);
+			if (endptr == NULL || *endptr != '\0') {
+				return luaL_error(L, "Invalid result %s", result);
+			} else {
+				lua_pushnumber(L, n);
+			}
+		} else {
+			lua_pushinteger(L, r);
+		}
 		return 1;
 	}
 	return 0;

lualib/skynet.lua

@@ -634,11 +634,15 @@ function skynet.start(start_func)
 end
 
 function skynet.endless()
-	return c.command("ENDLESS")~=nil
+	return (c.intcommand("STAT", "endless") == 1)
 end
 
 function skynet.mqlen()
-	return c.intcommand "MQLEN"
+	return c.intcommand("STAT", "mqlen")
+end
+
+function skynet.stat(what)
+	return c.intcommand("STAT", what)
 end
 
 function skynet.task(ret)

lualib/skynet/debug.lua

@@ -25,8 +25,10 @@ local function init(skynet, export)
 
 		function dbgcmd.STAT()
 			local stat = {}
-			stat.mqlen = skynet.mqlen()
 			stat.task = skynet.task()
+			stat.mqlen = skynet.stat "mqlen"
+			stat.cpu = skynet.stat "cpu"
+			stat.message = skynet.stat "message"
 			skynet.ret(skynet.pack(stat))
 		end
 

skynet-src/skynet_imp.h

@@ -4,6 +4,7 @@
 struct skynet_config {
 	int thread;
 	int harbor;
+	int profile;
 	const char * daemon;
 	const char * module_path;
 	const char * bootstrap;

skynet-src/skynet_main.c

@@ -26,7 +26,6 @@ optint(const char *key, int opt) {
 	return strtol(str, NULL, 10);
 }
 
-/*
 static int
 optboolean(const char *key, int opt) {
 	const char * str = skynet_getenv(key);
@@ -36,7 +35,6 @@ optboolean(const char *key, int opt) {
 	}
 	return strcmp(str,"true")==0;
 }
-*/
 
 static const char *
 optstring(const char *key,const char * opt) {
@@ -137,6 +135,7 @@ main(int argc, char *argv[]) {
 	config.daemon = optstring("daemon", NULL);
 	config.logger = optstring("logger", NULL);
 	config.logservice = optstring("logservice", "logger");
+	config.profile = optboolean("profile", 1);
 
 	lua_close(L);
 

skynet-src/skynet_server.c

@@ -10,6 +10,7 @@
 #include "skynet_monitor.h"
 #include "skynet_imp.h"
 #include "skynet_log.h"
+#include "skynet_timer.h"
 #include "spinlock.h"
 #include "atomic.h"
 
@@ -46,12 +47,15 @@ struct skynet_context {
 	skynet_cb cb;
 	struct message_queue *queue;
 	FILE * logfile;
+	uint64_t cpu_cost;	// in microsec
 	char result[32];
 	uint32_t handle;
 	int session_id;
 	int ref;
+	int message_count;
 	bool init;
 	bool endless;
+	bool profile;
 
 	CHECKCALLING_DECL
 };
@@ -61,6 +65,7 @@ struct skynet_node {
 	int init;
 	uint32_t monitor_exit;
 	pthread_key_t handle_key;
+	bool profile;	// default is off
 };
 
 static struct skynet_node G_NODE;
@@ -139,6 +144,10 @@ skynet_context_new(const char * name, const char *param) {
 
 	ctx->init = false;
 	ctx->endless = false;
+
+	ctx->cpu_cost = 0;
+	ctx->message_count = 0;
+	ctx->profile = G_NODE.profile;
 	// Should set to 0 first to avoid skynet_handle_retireall get an uninitialized handle
 	ctx->handle = 0;	
 	ctx->handle = skynet_handle_register(ctx);
@@ -256,7 +265,17 @@ dispatch_message(struct skynet_context *ctx, struct skynet_message *msg) {
 	if (ctx->logfile) {
 		skynet_log_output(ctx->logfile, msg->source, type, msg->session, msg->data, sz);
 	}
-	if (!ctx->cb(ctx, ctx->cb_ud, type, msg->session, msg->source, msg->data, sz)) {
+	++ctx->message_count;
+	int reserve_msg;
+	if (ctx->profile) {
+		uint64_t start_time = skynet_thread_time();
+		reserve_msg = ctx->cb(ctx, ctx->cb_ud, type, msg->session, msg->source, msg->data, sz);
+		uint64_t cost_time = skynet_thread_time() - start_time;
+		ctx->cpu_cost += cost_time;
+	} else {
+		reserve_msg = ctx->cb(ctx, ctx->cb_ud, type, msg->session, msg->source, msg->data, sz);
+	}
+	if (!reserve_msg) {
 		skynet_free(msg->data);
 	}
 	CHECKCALLING_END(ctx)
@@ -505,16 +524,6 @@ cmd_starttime(struct skynet_context * context, const char * param) {
 	return context->result;
 }
 
-static const char *
-cmd_endless(struct skynet_context * context, const char * param) {
-	if (context->endless) {
-		strcpy(context->result, "1");
-		context->endless = false;
-		return context->result;
-	}
-	return NULL;
-}
-
 static const char *
 cmd_abort(struct skynet_context * context, const char * param) {
 	skynet_handle_retireall();
@@ -539,9 +548,25 @@ cmd_monitor(struct skynet_context * context, const char * param) {
 }
 
 static const char *
-cmd_mqlen(struct skynet_context * context, const char * param) {
-	int len = skynet_mq_length(context->queue);
-	sprintf(context->result, "%d", len);
+cmd_stat(struct skynet_context * context, const char * param) {
+	if (strcmp(param, "mqlen") == 0) {
+		int len = skynet_mq_length(context->queue);
+		sprintf(context->result, "%d", len);
+	} else if (strcmp(param, "endless") == 0) {
+		if (context->endless) {
+			strcpy(context->result, "1");
+			context->endless = false;
+		} else {
+			strcpy(context->result, "0");
+		}
+	} else if (strcmp(param, "cpu") == 0) {
+		double t = (double)context->cpu_cost / 1000000.0;	// microsec
+		sprintf(context->result, "%lf", t);
+	} else if (strcmp(param, "message") == 0) {
+		sprintf(context->result, "%d", context->message_count);
+	} else {
+		context->result[0] = '\0';
+	}
 	return context->result;
 }
 
@@ -618,10 +643,9 @@ static struct command_func cmd_funcs[] = {
 	{ "GETENV", cmd_getenv },
 	{ "SETENV", cmd_setenv },
 	{ "STARTTIME", cmd_starttime },
-	{ "ENDLESS", cmd_endless },
 	{ "ABORT", cmd_abort },
 	{ "MONITOR", cmd_monitor },
-	{ "MQLEN", cmd_mqlen },
+	{ "STAT", cmd_stat },
 	{ "LOGON", cmd_logon },
 	{ "LOGOFF", cmd_logoff },
 	{ "SIGNAL", cmd_signal },
@@ -779,3 +803,7 @@ skynet_initthread(int m) {
 	pthread_setspecific(G_NODE.handle_key, (void *)v);
 }
 
+void
+skynet_profile_enable(int enable) {
+	G_NODE.profile = (bool)enable;
+}

skynet-src/skynet_server.h

@@ -26,4 +26,6 @@ void skynet_globalinit(void);
 void skynet_globalexit(void);
 void skynet_initthread(int m);
 
+void skynet_profile_enable(int enable);
+
 #endif

skynet-src/skynet_start.c

@@ -263,6 +263,7 @@ skynet_start(struct skynet_config * config) {
 	skynet_module_init(config->module_path);
 	skynet_timer_init();
 	skynet_socket_init();
+	skynet_profile_enable(config->profile);
 
 	struct skynet_context *ctx = skynet_context_new(config->logservice, config->logger);
 	if (ctx == NULL) {

skynet-src/skynet_timer.c

@@ -14,6 +14,8 @@
 
 #if defined(__APPLE__)
 #include <sys/time.h>
+#include <mach/task.h>
+#include <mach/mach.h>
 #endif
 
 typedef void (*timer_execute_func)(void *ud,void *arg);
@@ -296,3 +298,25 @@ skynet_timer_init(void) {
 	TI->current_point = gettime();
 }
 
+// for profile
+
+#define NANOSEC 1000000000
+#define MICROSEC 1000000
+
+uint64_t
+skynet_thread_time(void) {
+#if  !defined(__APPLE__)
+	struct timespec ti;
+	clock_gettime(CLOCK_THREAD_CPUTIME_ID, &ti);
+
+	return (uint64_t)ti.tv_sec * MICROSEC + (uint64_t)ti.tv_nsec / (NANOSEC / MICROSEC);
+#else
+	struct task_thread_times_info aTaskInfo;
+	mach_msg_type_number_t aTaskInfoCount = TASK_THREAD_TIMES_INFO_COUNT;
+	if (KERN_SUCCESS != task_info(mach_task_self(), TASK_THREAD_TIMES_INFO, (task_info_t )&aTaskInfo, &aTaskInfoCount)) {
+		return 0;
+	}
+
+	return (uint64_t)(aTaskInfo.user_time.seconds) + (uint64_t)aTaskInfo.user_time.microseconds;
+#endif
+}

skynet-src/skynet_timer.h

@@ -6,6 +6,7 @@
 int skynet_timeout(uint32_t handle, int time, int session);
 void skynet_updatetime(void);
 uint32_t skynet_starttime(void);
+uint64_t skynet_thread_time(void);	// for profile, in micro second
 
 void skynet_timer_init(void);