nicer

Author: Fallen-Breath

chatbridge/common/logger.py

@@ -1,15 +1,15 @@
 import os
 import sys
 import time
+import weakref
 import zipfile
 from logging import FileHandler, Formatter, Logger, DEBUG, StreamHandler, INFO
 from threading import RLock
-from typing import Optional
+from typing import Optional, Set
 
 from colorlog import ColoredFormatter
 
 LOGGING_DIR = os.path.join('logs')
-DEBUG_SWITCH = False
 
 
 class SyncStdoutStreamHandler(StreamHandler):
@@ -63,6 +63,14 @@ class ChatBridgeLogger(Logger):
 			'CRITICAL': 'red'
 		}
 	}
+	__DEBUG_SWITCH = False
+	__REFS: Set['ChatBridgeLogger'] = weakref.WeakSet()
+
+	@classmethod
+	def set_debug_all(cls, value: bool):
+		cls.__DEBUG_SWITCH = value
+		for logger in cls.__REFS:
+			logger.__refresh_debug_level()
 
 	def __init__(self, name: str, *, file_name: Optional[str] = None, file_handler: Optional[FileHandler] = None):
 		super().__init__(name)
@@ -80,7 +88,15 @@ def __init__(self, name: str, *, file_name: Optional[str] = None, file_handler:
 			self.file_handler = file_handler
 		if self.file_handler is not None:
 			self.addHandler(self.file_handler)
-		self.setLevel(DEBUG if DEBUG_SWITCH else INFO)
+		self.__REFS.add(self)
+		self.__refresh_debug_level()
+
+	@classmethod
+	def is_debug_enabled(cls) -> bool:
+		return cls.__DEBUG_SWITCH
+
+	def __refresh_debug_level(self):
+		self.setLevel(DEBUG if self.__DEBUG_SWITCH else INFO)
 
 	def close_file(self):
 		if self.file_handler is not None:

chatbridge/core/client.py

@@ -20,6 +20,7 @@
 
 
 class ClientStatus(Enum):
+	STARTING = auto()  # thread started
 	CONNECTING = auto()  # socket connecting
 	CONNECTED = auto()  # socket connected, logging in
 	ONLINE = auto()   # logged in, thread started
@@ -68,7 +69,7 @@ def _in_status(self, status: Union[ClientStatus, Collection[ClientStatus]]):
 
 	def _assert_status(self, status: Union[ClientStatus, Collection[ClientStatus]]):
 		if not self._in_status(status):
-			raise AssertionError('Excepted status {} but {} found'.format(set(status), self.__status))
+			raise AssertionError('Excepted status {} but {} found'.format(status, self.__status))
 
 	def _is_connected(self) -> bool:
 		return self._in_status({ClientStatus.CONNECTED, ClientStatus.ONLINE})
@@ -113,7 +114,7 @@ def __connect(self):
 		"""
 		status: STOPPED -> CONNECTED
 		"""
-		self._assert_status(ClientStatus.STOPPED)
+		self._assert_status(ClientStatus.STARTING)
 		self._set_status(ClientStatus.CONNECTING)
 		assert self.__server_address is not None
 		self.logger.info('Connecting to {}'.format(self.__server_address))
@@ -156,37 +157,26 @@ def _tick_connection(self):
 	# --------------
 
 	def start(self):
-		assert self._on_external_thread()
-		if not self._is_stopped():
-			self.logger.warning('Client is running, cannot start again')
-			return
-		acq = self.__start_stop_lock.acquire(blocking=False)
-		if not acq:
-			self.logger.warning('Client is already starting')
-			return
-		try:
-			self.logger.debug('Starting client')
-			self.__connection_done.clear()
-			super().start()
-			self.__connection_done.wait()
-		finally:
-			self.__start_stop_lock.release()
+		self.logger.debug('Starting client')
+		with self.__start_stop_lock:
+			if not self._is_stopped():
+				self.logger.warning('Client is running, cannot start again')
+				return
+			self._set_status(ClientStatus.STARTING)
+		self.__connection_done.clear()
+		super().start()
+		self.__connection_done.wait()
+		self.logger.debug('Started client')
 
 	def stop(self):
-		assert self._on_external_thread()
-		if self._is_stopped():
-			self.logger.warning('Client is stopped, cannot stop again')
-			return
-		acq = self.__start_stop_lock.acquire(blocking=False)
-		if not acq:
-			self.logger.warning('Client is already stopping')
-			return
-		try:
-			self.logger.debug('Stopping client')
-			self.__disconnect()
-			super().stop()
-		finally:
-			self.__start_stop_lock.release()
+		self.logger.debug('Stopping client')
+		with self.__start_stop_lock:
+			if self._is_stopped():
+				self.logger.warning('Client is stopped, cannot stop again')
+				return
+			self.__disconnect()  # state -> STOPPED or DISCONNECTED
+		super().stop()
+		self.logger.debug('Stopped client')
 
 	def restart(self):
 		self.logger.info('Restarting client')
@@ -205,7 +195,7 @@ def _main_loop(self):
 			self._connect_and_login()
 			self._set_status(ClientStatus.ONLINE)
 		except Exception as e:
-			self.logger.error('Failed to connect to {}: {}'.format(self.__server_address, e))
+			(self.logger.exception if self.logger.is_debug_enabled() else self.logger.error)('Failed to connect to {}: {}'.format(self.__server_address, e))
 			self.__disconnect()
 			self.__connection_done.set()
 		else:
@@ -230,11 +220,14 @@ def _main_loop(self):
 
 	def _on_started(self):
 		self.__connection_done.set()
-		self._start_keep_alive_thread()
+		self.__thread_keep_alive = self._start_keep_alive_thread()
 
 	def _on_stopped(self):
 		if self._is_connected():
 			self.__disconnect()
+		self.logger.debug('Joining keep alive thread')
+		self.__thread_keep_alive.join()
+		self.logger.debug('Joined keep alive thread')
 
 	# ----------------
 	#   Packet Logic
@@ -323,8 +316,8 @@ def reply_command(self, target: str, asker_payload: 'CommandPayload', result: Un
 	def _get_keep_alive_thread_name(cls):
 		return 'KeepAlive'
 
-	def _start_keep_alive_thread(self):
-		self._start_thread(self._keep_alive_loop, self._get_keep_alive_thread_name())
+	def _start_keep_alive_thread(self) -> Thread:
+		return self._start_thread(self._keep_alive_loop, self._get_keep_alive_thread_name())
 
 	def _keep_alive_target(self) -> str:
 		return constants.SERVER_NAME

chatbridge/core/network/basic.py

@@ -21,8 +21,7 @@ def __init__(self, name: str, aes_key: str):
 		self.aes_key = aes_key
 		self._cryptor = AESCryptor(aes_key)
 		self.__thread_run: Optional[Thread] = None
-		self.__threads: List[Thread] = []
-		self.__threads_lock = RLock()
+		self.__thread_run_lock = RLock()
 
 	def get_name(self) -> str:
 		return self.__name
@@ -39,7 +38,7 @@ def get_logging_file_name(self) -> Optional[str]:
 	def _start_thread(self, target: Callable, name: str) -> Thread:
 		thread = Thread(target=target, args=(), name=name, daemon=True)
 		thread.start()
-		self.__threads.append(thread)
+		self.logger.debug('Started thread {}: {}'.format(name, thread))
 		return thread
 
 	@classmethod
@@ -49,9 +48,11 @@ def _get_main_loop_thread_name(cls):
 	def start(self):
 		def func():
 			self._main_loop()
-			self.__clean_up()
+			self.logger.close_file()
+			with self.__thread_run_lock:
+				self.__thread_run = None
 
-		with self.__threads_lock:
+		with self.__thread_run_lock:
 			if self.__thread_run is not None:
 				raise RuntimeError('Already running')
 			self.__thread_run = self._start_thread(func, self._get_main_loop_thread_name())
@@ -61,26 +62,15 @@ def stop(self):
 		Stop the client/server, and wait until the MainLoop thread exits
 		Need to be called on a non-MainLoop thread
 		"""
-		self.__join_threads()
+		self.logger.debug('Joining MainLoop thread')
+		with self.__thread_run_lock:
+			thread = self.__thread_run
+		if thread is not None:
+			if thread is not current_thread():
+				thread.join()
+			else:
+				self.logger.warning('Joining current thread {}'.format(thread))
+		self.logger.debug('Joined MainLoop thread')
 
 	def _main_loop(self):
 		pass
-
-	def __clean_up(self):
-		self.logger.close_file()
-		self.__thread_run = None
-
-	def __join_threads(self):
-		self.logger.debug('Joining threads {}'.format(self.__threads))
-		with self.__threads_lock:
-			for thread in self.__threads:
-				if thread is not current_thread():
-					thread.join()
-				else:
-					self.logger.warning('Joining current thread {}'.format(thread))
-			self.__threads.clear()
-			self.__thread_run = None
-		self.logger.debug('Joined threads')
-
-	def _on_external_thread(self):
-		return current_thread() not in self.__threads

chatbridge/core/server.py

@@ -123,10 +123,13 @@ def start(self):
 
 	def __stop(self):
 		self.__stopping_flag = True
-		try:
-			self.__sock.close()
-		except:
-			pass
+		if self.__sock is not None:
+			try:
+				self.__sock.close()
+				self.__sock = None
+				self.logger.info('Socket closed')
+			except:
+				self.logger.exception('Error when stop close')
 
 	def stop(self):
 		self.__stop()

chatbridge/impl/cli/cli_client.py

@@ -12,7 +12,7 @@ def _on_started(self):
 		self.logger.info('Connected to the server')
 
 	def _on_stopped(self):
-		super()._on_started()
+		super()._on_stopped()
 		self.logger.info('Disconnected')
 
 	def on_chat(self, sender: str, payload: ChatPayload):
@@ -43,6 +43,7 @@ def console_loop(self):
 def main():
 	config: ClientConfig = utils.load_config(ConfigFile, ClientConfig)
 	client = CLIClient.create(config)
+	client.logger.set_debug_all(True)
 	print('AES Key = {}'.format(config.aes_key))
 	print('Client Info: name = {}, password = {}'.format(config.name, config.password))
 	print('Server address = {}'.format(client.get_server_address()))

chatbridge/impl/cli/cli_server.py

@@ -29,10 +29,17 @@ def console_loop(self):
 				self.logger.info('Client count: {}'.format(len(self.clients)))
 				for client in self.clients.values():
 					self.logger.info('- {}: online = {}, ping = {}'.format(client.info.name, client.is_online(), client.get_ping_text()))
+			elif text == 'debug on':
+				self.logger.set_debug_all(True)
+				self.logger.info('Debug logging on')
+			elif text == 'debug off':
+				self.logger.set_debug_all(False)
+				self.logger.info('Debug logging off')
 			else:
 				self.logger.info('stop": stop the server')
 				self.logger.info('stop <client_name>": stop a client')
 				self.logger.info('list": show the client list')
+				self.logger.info('debug on|off": switch debug logging')
 
 
 def main():

chatbridge/impl/mcdr/client.py

@@ -41,8 +41,7 @@ def _on_stopped(self):
 		self.logger.info('Client stopped')
 
 	def on_chat(self, sender: str, payload: ChatPayload):
-		if self.server is not None:
-			self.server.say(RText('[{}] {}'.format(sender, payload.formatted_str()), RColor.gray))
+		self.server.say(RText('[{}] {}'.format(sender, payload.formatted_str()), RColor.gray))
 
 	def on_command(self, sender: str, payload: CommandPayload):
 		command = payload.command

chatbridge/impl/mcdr/mcdr_entry.py

@@ -1,4 +1,5 @@
 import os
+import shutil
 from threading import Event, Lock
 from typing import Optional
 
@@ -29,7 +30,7 @@ def display_status(source: CommandSource):
 	if config is None or client is None:
 		source.reply(tr('status.not_init'))
 	else:
-		source.reply(tr('status.not_init', client.is_online()))
+		source.reply(tr('status.info', client.is_online(), client.get_ping_text()))
 
 
 @new_thread('ChatBridge-restart')
@@ -43,6 +44,7 @@ def restart_client(source: CommandSource):
 def on_unload(server: PluginServerInterface):
 	with cb_lock:
 		if client is not None and client.is_online():
+			server.logger.info('Stopping chatbridge client due to plugin unload')
 			client.stop()
 	cb_stop_done.set()
 
@@ -57,21 +59,28 @@ def send_chat(message: str, *, author: str = ''):
 
 
 def on_load(server: PluginServerInterface, old_module):
+	cb1_config_path = os.path.join('config', 'ChatBridge_client.json')
+	config_path = os.path.join(server.get_data_folder(), 'config.json')
+	if os.path.isfile(cb1_config_path) and not os.path.isfile(config_path):
+		shutil.copyfile(cb1_config_path, config_path)
+		server.logger.info('Migrated configure file from ChatBridge v1: {} -> {}'.format(cb1_config_path, config_path))
+		server.logger.info('You need to delete the old config file manually if you want')
+
 	global client, config
-	if not os.path.isfile(os.path.join('config', server.get_self_metadata().id, 'config.json')):
+	if not os.path.isfile(config_path):
 		server.logger.exception('Config file not found! ChatBridge will not work properly')
 		server.logger.error('Fill the default configure file with correct values and reload the plugin')
 		server.save_config_simple(MCDRClientConfig.get_default())
 		return
 
 	try:
-		config = server.load_config_simple(target_class=MCDRClientConfig)
+		config = server.load_config_simple(file_name=config_path, in_data_folder=False, target_class=MCDRClientConfig)
 	except:
 		server.logger.exception('Failed to read the config file! ChatBridge might not work properly')
 		server.logger.error('Fix the configure file and then reload the plugin')
-	if config.debug:
-		logger.DEBUG_SWITCH = True
 	client = ChatBridgeMCDRClient(config, server)
+	if config.debug:
+		client.logger.set_debug_all(True)
 	for prefix in Prefixes:
 		server.register_help_message(prefix, tr('help_summary'))
 	server.register_command(
@@ -88,6 +97,7 @@ def start():
 				stop_event: Event = old_module.cb_stop_done
 				if not stop_event.wait(30):
 					server.logger.warning('Previous chatbridge instance does not stop for 30s')
+			server.logger.info('Starting chatbridge client')
 			client.start()
 
 	start()

lang/en_us.yml

@@ -9,5 +9,8 @@ chatbridge:
   help_summary: 'Chatbridge control'
   status:
     not_init: 'Chatbridge is not initialized, please check the server console output'
-    info: 'Chatbridge online state: {}'
-  restarted: 'Chatbridge restarted'
+    info: |
+      Chatbridge status:
+        Online: {0}
+        ping: {1}
+    restarted: 'Chatbridge restarted'

lang/zh_cn.yml

@@ -9,5 +9,8 @@ chatbridge:
   help_summary: '跨服聊天控制'
   status:
     not_init: '跨服聊天未初始化，请检查服务端后台输出'
-    info: '跨服聊天客户端在线情况: {}'
+    info: |
+      跨服聊天状态:
+        在线: {0}
+        延迟: {1}
   restarted: '跨服聊天已重启'

requirements.txt

@@ -1,3 +1,3 @@
-mcdreforged>=2.0
+mcdreforged>=2.1.2
 pycryptodome
 colorlog