add message log

Makefile

@@ -48,7 +48,7 @@ LUA_CLIB = skynet socketdriver int64 bson mongo md5 netpack \
 SKYNET_SRC = skynet_main.c skynet_handle.c skynet_module.c skynet_mq.c \
   skynet_server.c skynet_start.c skynet_timer.c skynet_error.c \
   skynet_harbor.c skynet_env.c skynet_monitor.c skynet_socket.c socket_server.c \
-  malloc_hook.c skynet_daemon.c
+  malloc_hook.c skynet_daemon.c skynet_log.c
 
 all : \
   $(SKYNET_BUILD_PATH)/skynet \

examples/config

@@ -1,6 +1,7 @@
 root = "./"
 thread = 8
 logger = nil
+logpath = "."
 harbor = 1
 address = "127.0.0.1:2526"
 master = "127.0.0.1:2013"

lualib/skynet.lua

@@ -523,12 +523,7 @@ local function dispatch_message(...)
 end
 
 function skynet.newservice(name, ...)
-	local handle = skynet.tostring(skynet.rawcall(".launcher", "lua" , skynet.pack("LAUNCH", "snlua", name, ...)))
+	return skynet.call(".launcher", "lua" , "LAUNCH", "snlua", name, ...)
-	if handle == "" then
-		return nil
-	else
-		return string_to_handle(handle)
-	end
 end
 
 function skynet.uniqueservice(global, ...)

service/debug_console.lua

@@ -1,5 +1,6 @@
 local skynet = require "skynet"
 local codecache = require "skynet.codecache"
+local core = require "skynet.core"
 local socket = require "socket"
 local snax = require "snax"
 
@@ -120,6 +121,9 @@ function COMMAND.help()
 		service = "List unique service",
 		task = "task address : show service task detail",
 		inject = "inject address luascript.lua",
+		logon = "logon address",
+		logoff = "logoff address",
+		log = "launch a new lua service with log",
 	}
 end
 
@@ -136,6 +140,15 @@ function COMMAND.start(...)
 	end
 end
 
+function COMMAND.log(...)
+	local ok, addr = pcall(skynet.call, ".launcher", "lua", "LOGLAUNCH", "snlua", ...)
+	if ok then
+		return { [skynet.address(addr)] = ... }
+	else
+		return "Failed"
+	end
+end
+
 function COMMAND.snax(...)
 	local ok, s = pcall(snax.newservice, ...)
 	if ok then
@@ -181,3 +194,13 @@ function COMMAND.info(address)
 	address = adjust_address(address)
 	return skynet.call(address,"debug","INFO")
 end
+
+function COMMAND.logon(address)
+	address = adjust_address(address)
+	core.command("LOGON", skynet.address(address))
+end
+
+function COMMAND.logoff(address)
+	address = adjust_address(address)
+	core.command("LOGOFF", skynet.address(address))
+end

service/launcher.lua

@@ -1,4 +1,5 @@
 local skynet = require "skynet"
+local core = require "skynet.core"
 local string = string
 
 local services = {}
@@ -65,18 +66,29 @@ function command.REMOVE(_, handle)
 	return NORET
 end
 
-local function return_string(str)
+local function launch_service(service, ...)
-	return str
+	local param = table.concat({...}, " ")
+	local inst = skynet.launch(service, param)
+	local response = skynet.response()
+	if inst then
+		services[inst] = service .. " " .. param
+		instance[inst] = response
+	else
+		response(false)
+		return
+	end
+	return inst
 end
 
 function command.LAUNCH(_, service, ...)
-	local param = table.concat({...}, " ")
+	launch_service(service, ...)
-	local inst = skynet.launch(service, param)
+	return NORET
+end
+
+function command.LOGLAUNCH(_, service, ...)
+	local inst = launch_service(service, ...)
 	if inst then
-		services[inst] = service .. " " .. param
+		core.command("LOGON", skynet.address(inst))
-		instance[inst] = skynet.response(return_string)
-	else
-		skynet.ret("")	-- launch failed
 	end
 	return NORET
 end
@@ -97,7 +109,7 @@ function command.LAUNCHOK(address)
 	-- init notice
 	local response = instance[address]
 	if response then
-		response(true, skynet.address(address))
+		response(true, address)
 		instance[address] = nil
 	end
 
@@ -116,9 +128,7 @@ skynet.register_protocol {
 		elseif cmd == "ERROR" then
 			command.ERROR(address)
 		else
-			-- launch request
+			error ("Invalid text command " .. cmd)
-			local service, param = string.match(cmd,"([^ ]+) (.*)")
-			command.LAUNCH(_, service, param)
 		end
 	end,
 }

skynet-src/skynet_log.c

@@ -0,0 +1,77 @@
+#include "skynet_log.h"
+#include "skynet_timer.h"
+#include "skynet.h"
+#include "skynet_socket.h"
+#include <string.h>
+#include <time.h>
+
+FILE * 
+skynet_log_open(struct skynet_context * ctx, uint32_t handle) {
+	const char * logpath = skynet_getenv("logpath");
+	if (logpath == NULL)
+		return NULL;
+	size_t sz = strlen(logpath);
+	char tmp[sz + 16];
+	sprintf(tmp, "%s/%08x.log", logpath, handle);
+	FILE *f = fopen(tmp, "ab");
+	if (f) {
+		uint32_t starttime = skynet_gettime_fixsec();
+		uint32_t currenttime = skynet_gettime();
+		time_t ti = starttime + currenttime/100;
+		skynet_error(ctx, "Open log file %s", tmp);
+		fprintf(f, "open time: %u %s", currenttime, ctime(&ti));
+		fflush(f);
+	} else {
+		skynet_error(ctx, "Open log file %s fail", tmp);
+	}
+	return f;
+}
+
+void
+skynet_log_close(struct skynet_context * ctx, FILE *f, uint32_t handle) {
+	skynet_error(ctx, "Close log file :%08x", handle);
+	fprintf(f, "close time: %u\n", skynet_gettime());
+	fclose(f);
+}
+
+static void
+log_blob(FILE *f, void * buffer, size_t sz) {
+	size_t i;
+	uint8_t * buf = buffer;
+	for (i=0;i!=sz;i++) {
+		fprintf(f, "%02x", buf[i]);
+	}
+}
+
+static void
+log_socket(FILE * f, struct skynet_socket_message * message, size_t sz) {
+	fprintf(f, "[socket] %d %d %d ", message->type, message->id, message->ud);
+
+	if (message->buffer == NULL) {
+		const char *buffer = (const char *)(message + 1);
+		sz -= sizeof(*message);
+		const char * eol = memchr(buffer, '\0', sz);
+		if (eol) {
+			sz = eol - buffer;
+		}
+		fprintf(f, "[%*s]", (int)sz, (const char *)buffer);
+	} else {
+		sz = message->ud;
+		log_blob(f, message->buffer, sz);
+	}
+	fprintf(f, "\n");
+	fflush(f);
+}
+
+void 
+skynet_log_output(FILE *f, uint32_t source, int type, int session, void * buffer, size_t sz) {
+	if (type == PTYPE_SOCKET) {
+		log_socket(f, buffer, sz);
+	} else {
+		uint32_t ti = skynet_gettime();
+		fprintf(f, ":%08x %d %d %u ", source, type, session, ti);
+		log_blob(f, buffer, sz);
+		fprintf(f,"\n");
+		fflush(f);
+	}
+}

skynet-src/skynet_log.h

@@ -0,0 +1,14 @@
+#ifndef skynet_log_h
+#define skynet_log_h
+
+#include "skynet_env.h"
+#include "skynet.h"
+
+#include <stdio.h>
+#include <stdint.h>
+
+FILE * skynet_log_open(struct skynet_context * ctx, uint32_t handle);
+void skynet_log_close(struct skynet_context * ctx, FILE *f, uint32_t handle);
+void skynet_log_output(FILE *f, uint32_t source, int type, int session, void * buffer, size_t sz);
+
+#endif

skynet-src/skynet_server.c

@@ -9,6 +9,7 @@
 #include "skynet_env.h"
 #include "skynet_monitor.h"
 #include "skynet_imp.h"
+#include "skynet_log.h"
 
 #include <pthread.h>
 
@@ -37,13 +38,14 @@
 struct skynet_context {
 	void * instance;
 	struct skynet_module * mod;
-	uint32_t handle;
-	int ref;
-	char result[32];
 	void * cb_ud;
 	skynet_cb cb;
-	int session_id;
 	struct message_queue *queue;
+	FILE * logfile;
+	char result[32];
+	uint32_t handle;
+	int session_id;
+	int ref;
 	bool init;
 	bool endless;
 
@@ -129,6 +131,7 @@ skynet_context_new(const char * name, const char *param) {
 	ctx->cb = NULL;
 	ctx->cb_ud = NULL;
 	ctx->session_id = 0;
+	ctx->logfile = NULL;
 
 	ctx->init = false;
 	ctx->endless = false;
@@ -177,6 +180,9 @@ skynet_context_grab(struct skynet_context *ctx) {
 
 static void 
 delete_context(struct skynet_context *ctx) {
+	if (ctx->logfile) {
+		fclose(ctx->logfile);
+	}
 	skynet_module_instance_release(ctx->mod, ctx->instance);
 	skynet_mq_mark_release(ctx->queue);
 	skynet_free(ctx);
@@ -224,12 +230,15 @@ skynet_isremote(struct skynet_context * ctx, uint32_t handle, int * harbor) {
 }
 
 static void
-_dispatch_message(struct skynet_context *ctx, struct skynet_message *msg) {
+dispatch_message(struct skynet_context *ctx, struct skynet_message *msg) {
 	assert(ctx->init);
 	CHECKCALLING_BEGIN(ctx)
 	pthread_setspecific(G_NODE.handle_key, (void *)(uintptr_t)(ctx->handle));
 	int type = msg->sz >> HANDLE_REMOTE_SHIFT;
 	size_t sz = msg->sz & HANDLE_MASK;
+	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)) {
 		skynet_free(msg->data);
 	} 
@@ -242,7 +251,7 @@ skynet_context_dispatchall(struct skynet_context * ctx) {
 	struct skynet_message msg;
 	struct message_queue *q = ctx->queue;
 	while (!skynet_mq_pop(q,&msg)) {
-		_dispatch_message(ctx, &msg);
+		dispatch_message(ctx, &msg);
 	}
 }
 
@@ -280,7 +289,7 @@ skynet_context_message_dispatch(struct skynet_monitor *sm, struct message_queue
 		if (ctx->cb == NULL) {
 			skynet_free(msg.data);
 		} else {
-			_dispatch_message(ctx, &msg);
+			dispatch_message(ctx, &msg);
 		}
 
 		skynet_monitor_trigger(sm, 0,0);
@@ -412,17 +421,23 @@ cmd_exit(struct skynet_context * context, const char * param) {
 	return NULL;
 }
 
-static const char *
+static uint32_t
-cmd_kill(struct skynet_context * context, const char * param) {
+tohandle(struct skynet_context * context, const char * param) {
 	uint32_t handle = 0;
 	if (param[0] == ':') {
 		handle = strtoul(param+1, NULL, 16);
 	} else if (param[0] == '.') {
 		handle = skynet_handle_findname(param+1);
 	} else {
-		skynet_error(context, "Can't kill %s",param);
+		skynet_error(context, "Can't convert %s to handle",param);
-		// todo : kill global service
 	}
+
+	return handle;
+}
+
+static const char *
+cmd_kill(struct skynet_context * context, const char * param) {
+	uint32_t handle = tohandle(context, param);
 	if (handle) {
 		handle_exit(context, handle);
 	}
@@ -503,14 +518,7 @@ cmd_monitor(struct skynet_context * context, const char * param) {
 		}
 		return NULL;
 	} else {
-		if (param[0] == ':') {
+		handle = tohandle(context, param);
-			handle = strtoul(param+1, NULL, 16);
-		} else if (param[0] == '.') {
-			handle = skynet_handle_findname(param+1);
-		} else {
-			skynet_error(context, "Can't monitor %s",param);
-			// todo : monitor global service
-		}
 	}
 	G_NODE.monitor_exit = handle;
 	return NULL;
@@ -523,6 +531,48 @@ cmd_mqlen(struct skynet_context * context, const char * param) {
 	return context->result;
 }
 
+static const char *
+cmd_logon(struct skynet_context * context, const char * param) {
+	uint32_t handle = tohandle(context, param);
+	if (handle == 0)
+		return NULL;
+	struct skynet_context * ctx = skynet_handle_grab(handle);
+	if (ctx == NULL)
+		return NULL;
+	FILE *f = NULL;
+	FILE * lastf = ctx->logfile;
+	if (lastf == NULL) {
+		f = skynet_log_open(context, handle);
+		if (f) {
+			if (!__sync_bool_compare_and_swap(&ctx->logfile, NULL, f)) {
+				// logfile opens in other thread, close this one.
+				fclose(f);
+			}
+		}
+	}
+	skynet_context_release(ctx);
+	return NULL;
+}
+
+static const char *
+cmd_logoff(struct skynet_context * context, const char * param) {
+	uint32_t handle = tohandle(context, param);
+	if (handle == 0)
+		return NULL;
+	struct skynet_context * ctx = skynet_handle_grab(handle);
+	if (ctx == NULL)
+		return NULL;
+	FILE * f = ctx->logfile;
+	if (f) {
+		// logfile may close in other thread
+		if (__sync_bool_compare_and_swap(&ctx->logfile, f, NULL)) {
+			skynet_log_close(context, f, handle);
+		}
+	}
+	skynet_context_release(ctx);
+	return NULL;
+}
+
 static struct command_func cmd_funcs[] = {
 	{ "TIMEOUT", cmd_timeout },
 	{ "REG", cmd_reg },
@@ -539,6 +589,8 @@ static struct command_func cmd_funcs[] = {
 	{ "ABORT", cmd_abort },
 	{ "MONITOR", cmd_monitor },
 	{ "MQLEN", cmd_mqlen },
+	{ "LOGON", cmd_logon },
+	{ "LOGOFF", cmd_logoff },
 	{ NULL, NULL },
 };