Event logs and log replay

5 files changed, 299 insertions, 62 deletions

diff --git a/src/server/ConsoleInput.hx b/src/server/ConsoleInput.hx
index 8b2463f..3c287af 100644
--- a/src/server/ConsoleInput.hx
+++ b/src/server/ConsoleInput.hx
@@ -1,20 +1,59 @@
 package server;
 
+import haxe.extern.EitherType as Or;
+import haxe.io.Path;
+import haxe.Json;
+import sys.FileSystem;
+import sys.io.File;
 import js.html.Console;
 import js.node.Readline;
 import js.Node.process;
 using StringTools;
 
+private typedef CommandData = {
+	args:Array<String>,
+	desc:String
+}
+
+private enum abstract Command(String) from String {
+	var AddAdmin = "addAdmin";
+	var Replay = "replay";
+	var LogList = "logList";
+	var Exit = "exit";
+}
+
 class ConsoleInput {
 
 	final main:Main;
+	final commands:Map<Command, CommandData> = [
+		AddAdmin => {
+			args: ["name", "password"],
+			desc: "Adds channel admin"
+		},
+		Replay => {
+			args: ["name"],
+			desc: "Replay log file on server from user/logs/"
+		},
+		LogList => {
+			args: [],
+			desc: "Show log list from user/logs/"
+		},
+		Exit => {
+			args: [],
+			desc: "Exit process"
+		}
+	];
 
 	public function new(main:Main) {
 		this.main = main;
 	}
 
 	public function initConsoleInput():Void {
-		final rl = Readline.createInterface(process.stdin, process.stdout);
+		final rl = Readline.createInterface({
+			input: process.stdin,
+			output: process.stdout,
+			completer: onCompletion
+		});
 		haxe.Log.trace = (msg, ?pos) -> {
 			Readline.clearLine(process.stdout, 0);
 			Readline.cursorTo(process.stdout, 0, null);
@@ -29,31 +68,87 @@ class ConsoleInput {
 		// rl.on("close", exit);
 	}
 
-	function parseLine(line:String):Void {
-		if (line.startsWith("/addAdmin")) {
-			final args = line.split(" ");
-			if (args.length != 3) {
-				trace("Wrong count of arguments");
-				return;
-			}
-			final name = args[1];
-			final password = args[2];
-			if (main.badNickName(name)) {
-				final error = Lang.get("usernameError")
-					.replace("$MAX", '${main.config.maxLoginLength}');
-				trace(error);
-				return;
-			}
-			main.addAdmin(name, password);
+	function onCompletion(line:String):Array<Or<Array<String>, String>> {
+		final commands:Array<String> = [
+			for (item in commands.keys()) '/$item '
+		];
+		final matches = commands.filter(item -> item.startsWith(line));
+		if (matches.length > 0) return [matches, line];
+		return [commands, line];
+	}
 
-		} else if (line == "/exit") {
-			main.exit();
+	function parseLine(line:String):Void {
+		if (line.fastCodeAt(0) != "/".code || line.length < 2) {
+			printHelp(line);
 			return;
-		} else {
-			trace('Unknown command "$line". List:
-/addAdmin name password | Adds channel admin
-/exit | Exit process');
 		}
+		final args = line.trim().split(" ");
+		final command:Command = args.shift().substr(1);
+		if (commands[command] == null) {
+			printHelp(line);
+			return;
+		}
+		if (!isValidArgs(command, args)) return;
+
+		switch (command) {
+			case AddAdmin:
+				final name = args[0];
+				final password = args[1];
+				if (main.badNickName(name)) {
+					final error = Lang.get("usernameError")
+						.replace("$MAX", '${main.config.maxLoginLength}');
+					trace(error);
+					return;
+				}
+				main.addAdmin(name, password);
+
+			case Replay:
+				Utils.ensureDir(main.logsDir);
+				final name = args[0];
+				final path = Path.normalize('${main.logsDir}/$name.json');
+				if (!FileSystem.exists(path)) {
+					trace('File "$path" not found');
+					return;
+				}
+				final text = File.getContent(path);
+				final events:Array<ServerEvent> = Json.parse(text);
+				main.replayLog(events);
+
+			case LogList:
+				Utils.ensureDir(main.logsDir);
+				final names = FileSystem.readDirectory(main.logsDir)
+					.filter(s -> s.endsWith(".json"));
+				for (name in names) trace(Path.withoutExtension(name));
+
+			case Exit:
+				main.exit();
+		}
+	}
+
+	function isValidArgs(command:Command, args:Array<String>):Bool {
+		final len = args.length;
+		final actual = commands[command].args.length;
+		if (len != actual) {
+			trace('Wrong count of arguments for command "$command" ($len instead of $actual)');
+			return false;
+		}
+		return true;
+	}
+
+	function printHelp(line:String):Void {
+		var maxLength = 0;
+		for (name => data in commands) {
+			final len = '/$name ${data.args.join(" ")}'.length;
+			if (maxLength < len) maxLength = len;
+		}
+		final list:Array<String> = [];
+		for (name => data in commands) {
+			final args = data.args.join(" ");
+			final item = '/$name $args'.rpad(" ", maxLength);
+			list.push('$item | ${data.desc}');
+		}
+		final desc = list.join("\n");
+		trace('Unknown command "$line". List:\n$desc');
 	}
 
 }
diff --git a/src/server/Logger.hx b/src/server/Logger.hx
new file mode 100644
index 0000000..9ff4c34
--- /dev/null
+++ b/src/server/Logger.hx
@@ -0,0 +1,69 @@
+package server;
+
+import haxe.io.Path;
+import sys.io.File;
+import haxe.Json;
+import sys.FileSystem;
+using StringTools;
+using Lambda;
+
+class Logger {
+
+	final folder:String;
+	final maxCount:Int;
+	final verbose:Bool;
+	final logs:Array<ServerEvent> = [];
+	final matchFileFormat = ~/[0-9_-]+\.json$/;
+
+	public function new(folder:String, maxCount:Int, verbose:Bool):Void {
+		this.folder = folder;
+		this.maxCount = maxCount;
+		this.verbose = verbose;
+	}
+
+	public function log(event:ServerEvent):Void {
+		logs.push(event);
+		if (logs.length > 5000) logs.shift();
+	}
+
+	public function saveLog():Void {
+		if (logs.length == 0) return;
+		Utils.ensureDir(folder);
+		removeOldestLog(folder);
+		final name = DateTools.format(Date.now(), "%Y-%m-%d_%H_%M_%S");
+		File.saveContent('$folder/$name.json', Json.stringify(logs, filterNulls, "\t"));
+	}
+
+	function filterNulls(key:Any, value:Any):Any {
+		#if js
+		if (value == null) return js.Lib.undefined;
+		#end
+		return value;
+	}
+
+	function removeOldestLog(folder:String):Void {
+		final names = FileSystem.readDirectory(folder);
+		if (names.count(item -> matchFileFormat.match(item)) < maxCount) return;
+		var minDate = 0.0;
+		var fileName:String = null;
+		for (name in names) {
+			final date = extractFileDate(name).getTime();
+			if (minDate == 0 || minDate > date) {
+				minDate = date;
+				fileName = name;
+			}
+		}
+		if (fileName == null) return;
+		FileSystem.deleteFile('$folder/$fileName');
+	}
+
+	function extractFileDate(name:String):Date {
+		name = Path.withoutExtension(name);
+		final t = name.split("_");
+		final d = t.shift().split("-");
+		if (d.length != 3 && t.length != 3) return Date.fromTime(0);
+		final s = '${d[0]}-${d[1]}-${d[2]} ${t[0]}:${t[1]}:${t[2]}';
+		return Date.fromString(s);
+	}
+
+}
diff --git a/src/server/Main.hx b/src/server/Main.hx
index 3c85c3e..6c7753c 100644
--- a/src/server/Main.hx
+++ b/src/server/Main.hx
@@ -28,6 +28,7 @@ class Main {
 	static inline var VIDEO_START_MAX_DELAY = 3000;
 	static inline var VIDEO_SKIP_DELAY = 1000;
 	final rootDir = '$__dirname/..';
+	public final logsDir:String;
 	final verbose:Bool;
 	final statePath:String;
 	final wss:WSServer;
@@ -43,6 +44,7 @@ class Main {
 	final videoList = new VideoList();
 	final videoTimer = new VideoTimer();
 	final messages:Array<Message> = [];
+	final logger:Logger;
 	var isPlaylistOpen = true;
 	var itemPos = 0;
 
@@ -51,6 +53,7 @@ class Main {
 	function new() {
 		verbose = Sys.args().has("--verbose");
 		statePath = '$rootDir/user/state.json';
+		logsDir = '$rootDir/user/logs';
 		// process.on("exit", exit);
 		process.on("SIGINT", exit); // ctrl+c
 		process.on("SIGUSR1", exit); // kill pid
@@ -67,6 +70,7 @@ class Main {
 			logError("unhandledRejection", reason);
 			exit();
 		});
+		logger = new Logger(logsDir, 10, verbose);
 		consoleInput = new ConsoleInput(this);
 		consoleInput.initConsoleInput();
 		initIntergationHandlers();
@@ -101,6 +105,7 @@ class Main {
 
 	public function exit():Void {
 		saveState();
+		logger.saveLog();
 		if (wss == null) {
 			process.exit();
 			return;
@@ -162,9 +167,7 @@ class Main {
 
 	function writeUsers(users:UserList):Void {
 		final folder = '$rootDir/user';
-		if (!FileSystem.exists(folder)) {
-			FileSystem.createDirectory(folder);
-		}
+		Utils.ensureDir(folder);
 		final data = Json.stringify(users, "\t");
 		File.saveContent('$folder/users.json', data);
 	}
@@ -203,7 +206,7 @@ class Main {
 	function logError(type:String, data:Dynamic):Void {
 		trace(type, data);
 		final crashesFolder = '$rootDir/user/crashes';
-		if (!FileSystem.exists(crashesFolder)) FileSystem.createDirectory(crashesFolder);
+		Utils.ensureDir(crashesFolder);
 		final name = DateTools.format(Date.now(), "%Y-%m-%d_%H_%M_%S") + "-" + type;
 		File.saveContent('$crashesFolder/$name.json', Json.stringify(data, "\t"));
 	}
@@ -234,6 +237,36 @@ class Main {
 		trace('Admin $name added.');
 	}
 
+	public function replayLog(events:Array<ServerEvent>):Void {
+		final timer = new Timer(1000);
+		timer.run = () -> {
+			if (events.length == 0) {
+				timer.stop();
+				return;
+			}
+			final e = events.shift();
+			switch (e.event.type) {
+				case Connected:
+					if (clients.getByName(e.clientName) == null) {
+						final ws:Any = {send: () -> {}};
+						final id = freeIds.length > 0 ? freeIds.shift() : clients.length;
+						final client = new Client(ws, null, id, e.clientName, e.clientGroup);
+						clients.push(client);
+					}
+					onMessage(clients.getByName(e.clientName), e.event, true);
+				case Login:
+					final name = e.event.login.clientName;
+					final hash = e.event.login.passHash;
+					if (hash != null && !userList.admins.exists(a -> a.name == name)) {
+						e.event.login.passHash = null;
+					}
+					onMessage(clients.getByName(e.clientName), e.event, true);
+				default:
+					onMessage(clients.getByName(e.clientName), e.event, true);
+			}
+		}
+	}
+
 	function onConnect(ws:WebSocket, req:IncomingMessage):Void {
 		final ip = req.connection.remoteAddress;
 		final id = freeIds.length > 0 ? freeIds.shift() : clients.length;
@@ -243,26 +276,9 @@ class Main {
 		final client = new Client(ws, req, id, name, 0);
 		client.isAdmin = isAdmin;
 		clients.push(client);
-		if (clients.length == 1 && videoList.length > 0)
-			if (videoTimer.isPaused()) videoTimer.play();
-
-		send(client, {
-			type: Connected,
-			connected: {
-				config: config,
-				history: messages,
-				isUnknownClient: true,
-				clientName: client.name,
-				clients: [
-					for (client in clients) client.getData()
-				],
-				videoList: videoList,
-				isPlaylistOpen: isPlaylistOpen,
-				itemPos: itemPos,
-				globalIp: globalIp
-			}
-		});
-		sendClientList();
+		onMessage(client, {
+			type: Connected
+		}, true);
 
 		ws.on("message", data -> {
 			final obj = wsEventParser.fromJson(data);
@@ -274,26 +290,59 @@ class Main {
 				serverMessage(client, errors);
 				return;
 			}
-			onMessage(client, obj);
+			onMessage(client, obj, false);
 		});
+
 		ws.on("close", err -> {
-			trace('Client ${client.name} disconnected');
-			Utils.sortedPush(freeIds, client.id);
-			clients.remove(client);
-			sendClientList();
-			if (client.isLeader) {
-				if (videoTimer.isPaused()) videoTimer.play();
-			}
-			if (clients.length == 0) {
-				if (waitVideoStart != null) waitVideoStart.stop();
-				videoTimer.pause();
-			}
+			onMessage(client, {
+				type: Disconnected
+			}, true);
 		});
 	}
 
-	function onMessage(client:Client, data:WsEvent):Void {
+	function onMessage(client:Client, data:WsEvent, internal:Bool):Void {
+		logger.log({
+			clientName: client.name,
+			clientGroup: client.group.toInt(),
+			event: data,
+			time: Date.now().getTime()
+		});
 		switch (data.type) {
 			case Connected:
+				if (!internal) return;
+				if (clients.length == 1 && videoList.length > 0)
+					if (videoTimer.isPaused()) videoTimer.play();
+
+				send(client, {
+					type: Connected,
+					connected: {
+						config: config,
+						history: messages,
+						isUnknownClient: true,
+						clientName: client.name,
+						clients: clientList(),
+						videoList: videoList,
+						isPlaylistOpen: isPlaylistOpen,
+						itemPos: itemPos,
+						globalIp: globalIp
+					}
+				});
+				sendClientListExcept(client);
+
+			case Disconnected:
+				if (!internal) return;
+				trace('Client ${client.name} disconnected');
+				Utils.sortedPush(freeIds, client.id);
+				clients.remove(client);
+				sendClientList();
+				if (client.isLeader) {
+					if (videoTimer.isPaused()) videoTimer.play();
+				}
+				if (clients.length == 0) {
+					if (waitVideoStart != null) waitVideoStart.stop();
+					videoTimer.pause();
+				}
+
 			case UpdateClients:
 				sendClientList();
 			case Login:
@@ -330,7 +379,7 @@ class Main {
 						clients: clientList()
 					}
 				});
-				sendClientList();
+				sendClientListExcept(client);
 
 			case PasswordRequest:
 			case LoginError:
@@ -347,7 +396,7 @@ class Main {
 						clients: clientList()
 					}
 				});
-				sendClientList();
+				sendClientListExcept(client);
 
 			case Message:
 				if (!checkPermission(client, WriteChatPerm)) return;
@@ -582,6 +631,15 @@ class Main {
 		});
 	}
 
+	function sendClientListExcept(skipped:Client):Void {
+		broadcastExcept(skipped, {
+			type: UpdateClients,
+			updateClients: {
+				clients: clientList()
+			}
+		});
+	}
+
 	function serverMessage(client:Client, textId:String):Void {
 		send(client, {
 			type: ServerMessage, serverMessage: {
diff --git a/src/server/ServerEvent.hx b/src/server/ServerEvent.hx
new file mode 100644
index 0000000..6b9080f
--- /dev/null
+++ b/src/server/ServerEvent.hx
@@ -0,0 +1,10 @@
+package server;
+
+import Types.WsEvent;
+
+typedef ServerEvent = {
+	time:Float,
+	clientName:String,
+	clientGroup:Int,
+	event:WsEvent
+}
diff --git a/src/server/Utils.hx b/src/server/Utils.hx
index abce1c0..40fa282 100644
--- a/src/server/Utils.hx
+++ b/src/server/Utils.hx
@@ -1,10 +1,15 @@
 package server;
 
+import sys.FileSystem;
 import js.node.Https;
 import js.node.Os;
 
 class Utils {
 
+	public static function ensureDir(path:String):Void {
+		if (!FileSystem.exists(path)) FileSystem.createDirectory(path);
+	}
+
 	public static function getGlobalIp(callback:(ip:String)->Void):Void {
 		// untyped to skip second null argument for node < v10
 		Https.get(untyped "https://myexternalip.com/raw", r -> {