Much better logging, gives feedback during process

WebServer/static/exchange_client.py

@@ -1,3 +1,5 @@
+import logging
+from logging.config import dictConfig
 from typing import Optional, Callable
 
 from Crypto.PublicKey.ECC import EccKey
@@ -7,6 +9,45 @@ from SantaExchange.MessageHandler import MessageHandler
 from SantaExchange.SantasBrain import Brain
 from SantaExchange.UserInterface import UserInterface
 
+logging_function: Optional[Callable[[str], None]] = None
+
+
+class ExchangeLogger(logging.Handler):
+	def emit(self, record: logging.LogRecord):
+		if logging_function is not None:
+			logging_function(record.message)
+
+
+LOGGING_SETTINGS = {
+	'version': 1,
+	'disable_existing_loggers': False,
+	'formatters': {
+		'std_formatter': {'format': '%(message)s'}
+	},
+	'handlers': {
+		'stdhandler': {
+			'class': 'logging.StreamHandler',
+			'formatter': 'std_formatter',
+			'stream': 'ext://sys.stdout'
+		},
+		'ExchangeLogger': {
+			'class': f'{__name__}.ExchangeLogger',
+			'formatter': 'std_formatter',
+			'level': 'INFO'
+		}
+	},
+	'loggers': {
+		'root': {
+			'handlers': ['stdhandler', 'ExchangeLogger'],
+			'level': 'NOTSET',
+			'propagate': True
+		}
+	}
+}
+
+dictConfig(LOGGING_SETTINGS)
+
+
 class ExchangeClient(MessageHandler, UserInterface):
 	def __init__(self, send_message_function, receive_user_function, announce_recipient_function):
 		MessageHandler.__init__(self)

WebServer/static/exchange_worker.js

@@ -21,13 +21,13 @@ async function prepare() {
 	}
 
 	function printLogs(record) {
-	    console.log(record);
+	    postMessage({type: 'status', stage: 'exchange', text: record});
 	}
 
 	pyodide.globals.set('send_message', sendMessage);
 	pyodide.globals.set('receive_user', receiveUser);
 	pyodide.globals.set('announce_recipient', announceRecipient);
-	pyodide.globals.set('print_logs_function', printLogs);
+	pyodide.globals.set('logging_function', printLogs);
 
 	pyodide.runPython(`
         exchange_worker = ExchangeClient(send_message, receive_user, announce_recipient)

src/SantaExchange/SantasBrain.py

@@ -216,7 +216,6 @@ class Brain:
 					or self.announcement_build_cipher is None
 					or self.announcement_shuffle_cipher is None
 			):
-				logger.debug('Building ciphers')
 				should_continue = self.build_ciphers()
 				if not should_continue:
 					return messages_to_send
@@ -226,7 +225,6 @@ class Brain:
 
 			# Shuffle cards
 			if not self.sent_card_shuffling:
-				logger.debug('Shuffling vards')
 				shuffle_message = self.build_shuffle_message(all_participants)
 				if shuffle_message is None:
 					return messages_to_send
@@ -235,7 +233,6 @@ class Brain:
 
 			# Decrypt shuffled cards
 			if not self.sent_card_decryption:
-				logger.debug('Decrypting shuffled cards')
 				decrypt_cards_message = self.build_decrypt_cards_message(all_participants)
 				if decrypt_cards_message is None:
 					return messages_to_send
@@ -359,6 +356,7 @@ class Brain:
 
 			received_seeds.append(received_seed)
 		# Next, create a combined random seed from all the provided seeds
+		logger.info('Building cryptographic ciphers')
 		number_of_seed_bytes = max(len(seed) for seed in received_seeds)
 		total_seed = b'\0' * number_of_seed_bytes
 		for received_seed in received_seeds:
@@ -401,6 +399,7 @@ class Brain:
 			card_deck = [card for card in message.get_cards()]
 
 		# Shuffle by drawing random numbers from secret
+		logger.info('Shuffling encrypted cards')
 		shuffled_deck = []
 		while len(card_deck) > 0:
 			drawn_card = secrets.randbelow(len(card_deck))
@@ -432,6 +431,7 @@ class Brain:
 		if message is None:
 			return None
 
+		logger.info('Decrypting shuffled cards')
 		card_deck = message.get_cards()
 		decrypted_cards = []
 		for index, card_value in enumerate(card_deck):
@@ -448,7 +448,7 @@ class Brain:
 		return ShuffleMessage(self.own_name, decrypted_cards, DECRYPT_CARDS_STAGE)
 
 	def decrypt_card_value(self, card: bytes):
-		logger.debug('Decrypting own drawn card')
+		logger.info('Decrypting drawn card')
 		decrypted_card_bytes = self.card_exchange_cipher.decode(card)
 		if decrypted_card_bytes not in self.card_values:
 			logging.critical(f'Received an invalid card after shuffling. Secret santa exchange failed!')
@@ -477,6 +477,7 @@ class Brain:
 
 			card_deck = [card for card in message.get_cards()]
 
+		logger.info('Creating anonymous message')
 		anonymous_message = {
 			'card_no': self.card_drawn,
 			'key': self.secret_key.public_key().export_key(format='OpenSSH')
@@ -515,6 +516,7 @@ class Brain:
 		if card_deck is None:
 			return None
 
+		logger.info('Building deck of anonymous messages')
 		encrypted_deck = []
 		for index, card_value in enumerate(card_deck):
 			if index == own_index:
@@ -553,6 +555,7 @@ class Brain:
 		if card_deck is None:
 			return None
 
+		logger.info('Shuffling anonymous messages')
 		shuffled_cards = []
 		while len(card_deck) > 0:
 			draw_number = secrets.randbelow(len(card_deck))
@@ -595,6 +598,7 @@ class Brain:
 		if card_deck is None:
 			return None
 
+		logger.info('Decrypting anonymous messages')
 		decrypted_deck = [self.announcement_shuffle_cipher.decode(card_value) for card_value in card_deck]
 		shuffle_message = ShuffleMessage(self.own_name, decrypted_deck, DECRYPT_ANONYMOUS_STAGE)
 
@@ -646,6 +650,7 @@ class Brain:
 		if self.anonymous_keys is None:
 			return None
 
+		logger.info("Creating encrypted announcement for secret santa")
 		santa_card = (self.card_drawn - 1) % len(all_participants)
 
 		santa_key = self.anonymous_keys[santa_card]