Added multiple log features.

* [Reintroduced](https://github.com/Torxed/archinstall/blob/f64a605449f59c677dff39962f1cb46616d893b7/archinstall.py#L57-L71) log levels
* Created a global log file definition
* Optional support for `python-systemd`'s journald handler.
* Optional file output that has a globally configurable definition, that archinstall will honor in `archinstall.storage['logfile']`.

7 files changed, 139 insertions, 39 deletions

diff --git a/archinstall/lib/disk.py b/archinstall/lib/disk.py
index 0d0285d2..6ac97b04 100644
--- a/archinstall/lib/disk.py
+++ b/archinstall/lib/disk.py
@@ -2,6 +2,7 @@ import glob, re, os, json
 from collections import OrderedDict
 from .exceptions import DiskError
 from .general import *
+from .output import log, LOG_LEVELS
 
 ROOT_DIR_PATTERN = re.compile('^.*?/devices')
 GPT = 0b00000001
@@ -115,7 +116,7 @@ class Partition():
 			return f'Partition(path={self.path}, fs={self.filesystem}, mounted={self.mountpoint})'
 
 	def format(self, filesystem):
-		log(f'Formatting {self} -> {filesystem}')
+		log(f'Formatting {self} -> {filesystem}', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
 		if filesystem == 'btrfs':
 			o = b''.join(sys_command(f'/usr/bin/mkfs.btrfs -f {self.path}'))
 			if b'UUID' not in o:
@@ -154,7 +155,7 @@ class Partition():
 
 	def mount(self, target, fs=None, options=''):
 		if not self.mountpoint:
-			log(f'Mounting {self} to {target}')
+			log(f'Mounting {self} to {target}', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
 			if not fs:
 				if not self.filesystem: raise DiskError(f'Need to format (or define) the filesystem on {self} before mounting.')
 				fs = self.filesystem
@@ -216,7 +217,7 @@ class Filesystem():
 			self.add_partition('primary', start='513MiB', end='100%', format='ext4')
 
 	def add_partition(self, type, start, end, format=None):
-		log(f'Adding partition to {self.blockdevice}')
+		log(f'Adding partition to {self.blockdevice}', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
 		if format:
 			return self.parted(f'{self.blockdevice.device} mkpart {type} {format} {start} {end}') == 0
 		else:
diff --git a/archinstall/lib/general.py b/archinstall/lib/general.py
index abcf25f0..025dcc8b 100644
--- a/archinstall/lib/general.py
+++ b/archinstall/lib/general.py
@@ -4,7 +4,7 @@ from datetime import datetime, date
 from subprocess import Popen, STDOUT, PIPE, check_output
 from select import epoll, EPOLLIN, EPOLLHUP
 from .exceptions import *
-from .output import *
+from .output import log, LOG_LEVELS
 
 def gen_uid(entropy_length=256):
 	return hashlib.sha512(os.urandom(entropy_length)).hexdigest()
@@ -77,8 +77,11 @@ class sys_command():#Thread):
 		kwargs.setdefault("emulate", False)
 		kwargs.setdefault("suppress_errors", False)
 
+		self.log = kwargs.get('log', log)
+
 		if kwargs['emulate']:
-			log(f"Starting command '{cmd}' in emulation mode.")
+			self.log(f"Starting command '{cmd}' in emulation mode.", level=LOG_LEVELS.Debug)
+
 		self.raw_cmd = cmd
 		try:
 			self.cmd = shlex.split(cmd)
@@ -105,8 +108,8 @@ class sys_command():#Thread):
 			# "which" doesn't work as it's a builtin to bash.
 			# It used to work, but for whatever reason it doesn't anymore. So back to square one..
 
-			#log('Worker command is not executed with absolute path, trying to find: {}'.format(self.cmd[0]), origin='spawn', level=5)
-			#log('This is the binary {} for {}'.format(o.decode('UTF-8'), self.cmd[0]), origin='spawn', level=5)
+			#self.log('Worker command is not executed with absolute path, trying to find: {}'.format(self.cmd[0]), origin='spawn', level=5)
+			#self.log('This is the binary {} for {}'.format(o.decode('UTF-8'), self.cmd[0]), origin='spawn', level=5)
 			self.cmd[0] = locate_binary(self.cmd[0])
 
 		if not os.path.isdir(self.exec_dir):
@@ -150,7 +153,7 @@ class sys_command():#Thread):
 					os.execv(self.cmd[0], self.cmd)
 				except FileNotFoundError:
 					self.status = 'done'
-					log(f"{self.cmd[0]} does not exist.", origin='spawn', level=2)
+					self.log(f"{self.cmd[0]} does not exist.", level=LOG_LEVELS.Debug)
 					self.exit_code = 1
 					return False
 
@@ -160,8 +163,8 @@ class sys_command():#Thread):
 		poller.register(child_fd, EPOLLIN | EPOLLHUP)
 
 		if 'events' in self.kwargs and 'debug' in self.kwargs:
-			log(f'[D] Using triggers for command: {self.cmd}')
-			log(json.dumps(self.kwargs['events']))
+			self.log(f'[D] Using triggers for command: {self.cmd}', level=LOG_LEVELS.Debug)
+			self.log(json.dumps(self.kwargs['events']), level=LOG_LEVELS.Debug)
 
 		alive = True
 		last_trigger_pos = 0
@@ -175,7 +178,7 @@ class sys_command():#Thread):
 					break
 
 				if 'debug' in self.kwargs and self.kwargs['debug'] and len(output):
-					log(self.cmd, 'gave:', output.decode('UTF-8'))
+					self.log(self.cmd, 'gave:', output.decode('UTF-8'), level=LOG_LEVELS.Debug)
 
 				if 'on_output' in self.kwargs:
 					self.kwargs['on_output'](self.kwargs['worker'], output)
@@ -196,8 +199,8 @@ class sys_command():#Thread):
 							trigger_pos = self.trace_log[last_trigger_pos:].lower().find(trigger.lower())
 
 							if 'debug' in self.kwargs and self.kwargs['debug']:
-								log(f"Writing to subprocess {self.cmd[0]}: {self.kwargs['events'][trigger].decode('UTF-8')}")
-								log(f"Writing to subprocess {self.cmd[0]}: {self.kwargs['events'][trigger].decode('UTF-8')}", origin='spawn', level=5)
+								self.log(f"Writing to subprocess {self.cmd[0]}: {self.kwargs['events'][trigger].decode('UTF-8')}", level=LOG_LEVELS.Debug)
+								self.log(f"Writing to subprocess {self.cmd[0]}: {self.kwargs['events'][trigger].decode('UTF-8')}", level=LOG_LEVELS.Debug)
 
 							last_trigger_pos = trigger_pos
 							os.write(child_fd, self.kwargs['events'][trigger])
@@ -211,18 +214,18 @@ class sys_command():#Thread):
 					## Adding a exit trigger:
 					if len(self.kwargs['events']) == 0:
 						if 'debug' in self.kwargs and self.kwargs['debug']:
-							log(f"Waiting for last command {self.cmd[0]} to finish.", origin='spawn', level=4)
+							self.log(f"Waiting for last command {self.cmd[0]} to finish.", level=LOG_LEVELS.Debug)
 
 						if bytes(f']$'.lower(), 'UTF-8') in self.trace_log[0-len(f']$')-5:].lower():
 							if 'debug' in self.kwargs and self.kwargs['debug']:
-								log(f"{self.cmd[0]} has finished.")
+								self.log(f"{self.cmd[0]} has finished.", level=LOG_LEVELS.Debug)
 							alive = False
 							break
 
 		self.status = 'done'
 
 		if 'debug' in self.kwargs and self.kwargs['debug']:
-			log(f"{self.cmd[0]} waiting for exit code.")
+			self.log(f"{self.cmd[0]} waiting for exit code.", level=LOG_LEVELS.Debug)
 
 		if not self.kwargs['emulate']:
 			try:
@@ -236,14 +239,14 @@ class sys_command():#Thread):
 			self.exit_code = 0
 
 		if 'debug' in self.kwargs and self.kwargs['debug']:
-			log(f"{self.cmd[0]} got exit code: {self.exit_code}")
+			self.log(f"{self.cmd[0]} got exit code: {self.exit_code}", level=LOG_LEVELS.Debug)
 
 		if 'ignore_errors' in self.kwargs:
 			self.exit_code = 0
 
 		if self.exit_code != 0 and not self.kwargs['suppress_errors']:
-			log(f"'{self.raw_cmd}' did not exit gracefully, exit code {self.exit_code}.")
-			log(self.trace_log.decode('UTF-8'))
+			self.log(f"'{self.raw_cmd}' did not exit gracefully, exit code {self.exit_code}.", level=LOG_LEVELS.Debug)
+			self.log(self.trace_log.decode('UTF-8'), level=LOG_LEVELS.Debug)
 			raise SysCallError(f"'{self.raw_cmd}' did not exit gracefully, exit code {self.exit_code}.\n{self.trace_log.decode('UTF-8')}")
 
 		self.ended = time.time()
diff --git a/archinstall/lib/installer.py b/archinstall/lib/installer.py
index 0e5f5ca7..553fad80 100644
--- a/archinstall/lib/installer.py
+++ b/archinstall/lib/installer.py
@@ -1,4 +1,4 @@
-import os, stat
+import os, stat, time
 
 from .exceptions import *
 from .disk import *
@@ -6,6 +6,8 @@ from .general import *
 from .user_interaction import *
 from .profiles import Profile
 from .mirrors import *
+from .output import log, LOG_LEVELS
+from .storage import storage
 
 class Installer():
 	"""
@@ -35,6 +37,8 @@ class Installer():
 		self.profile = profile
 		self.hostname = hostname
 		self.mountpoint = mountpoint
+		self.init_time = time.strftime('%Y-%m-%d %H:%M:%S')
+		self.milliseconds = int(str(time.time()).split('.')[1])
 
 		self.helper_flags = {
 			'bootloader' : False,
@@ -43,10 +47,25 @@ class Installer():
 		}
 
 		self.base_packages = base_packages.split(' ')
+		storage['session'] = self
 
 		self.partition = partition
 		self.boot_partition = boot_partition
 
+	@property
+	def log(self, message, *args, level=LOG_LEVELS.Debug, file=None, **kwargs):
+		if not file:
+			if 'logfile' not in storage:
+				log_root = os.path.join(os.path.expanduser('~/'), '.cache/archinstall')
+				if not os.path.isdir(log_root):
+					os.makedirs(log_root)
+
+				storage['logfile'] = f"{log_root}/install-session_{self.init_time}.{self.milliseconds}.log"
+
+			file = storage['logfile']
+
+		log(message, *args, level=level, file=file, **kwargs)
+
 	def __enter__(self, *args, **kwargs):
 		self.partition.mount(self.mountpoint)
 		os.makedirs(f'{self.mountpoint}/boot', exist_ok=True)
@@ -60,14 +79,14 @@ class Installer():
 			raise args[1]
 
 		if not (missing_steps := self.post_install_check()):
-			log('Installation completed without any errors. You may now reboot.', bg='black', fg='green')
+			self.log('Installation completed without any errors. You may now reboot.', bg='black', fg='green')
 			return True
 		else:
-			log('Some required steps were not successfully installed/configured before leaving the installer:', bg='black', fg='red')
+			self.log('Some required steps were not successfully installed/configured before leaving the installer:', bg='black', fg='red')
 			for step in missing_steps:
-				log(f' - {step}', bg='black', fg='red')
-			log(f"Detailed error logs can be found at: {log_path}")
-			log(f"Submit this zip file as an issue to https://github.com/Torxed/archinstall/issues")
+				self.log(f' - {step}', bg='black', fg='red')
+			self.log(f"Detailed error logs can be found at: {log_path}")
+			self.log(f"Submit this zip file as an issue to https://github.com/Torxed/archinstall/issues")
 			return False
 
 	def post_install_check(self, *args, **kwargs):
@@ -75,15 +94,15 @@ class Installer():
 
 	def pacstrap(self, *packages, **kwargs):
 		if type(packages[0]) in (list, tuple): packages = packages[0]
-		log(f'Installing packages: {packages}')
+		self.log(f'Installing packages: {packages}')
 
 		if (sync_mirrors := sys_command('/usr/bin/pacman -Syy')).exit_code == 0:
 			if (pacstrap := sys_command(f'/usr/bin/pacstrap {self.mountpoint} {" ".join(packages)}', **kwargs)).exit_code == 0:
 				return True
 			else:
-				log(f'Could not strap in packages: {pacstrap.exit_code}')
+				self.log(f'Could not strap in packages: {pacstrap.exit_code}')
 		else:
-			log(f'Could not sync mirrors: {sync_mirrors.exit_code}')
+			self.log(f'Could not sync mirrors: {sync_mirrors.exit_code}')
 
 	def set_mirrors(self, mirrors):
 		return use_mirrors(mirrors, destination=f'{self.mountpoint}/etc/pacman.d/mirrorlist')
@@ -116,13 +135,13 @@ class Installer():
 		return True
 
 	def activate_ntp(self):
-		log(f'Installing and activating NTP.')
+		self.log(f'Installing and activating NTP.')
 		if self.pacstrap('ntp'):
 			if self.enable_service('ntpd'):
 				return True
 
 	def enable_service(self, service):
-		log(f'Enabling service {service}')
+		self.log(f'Enabling service {service}')
 		return self.arch_chroot(f'systemctl enable {service}').exit_code == 0
 
 	def run_command(self, cmd, *args, **kwargs):
@@ -171,7 +190,7 @@ class Installer():
 		return True
 
 	def add_bootloader(self, bootloader='systemd-bootctl'):
-		log(f'Adding bootloader {bootloader} to {self.boot_partition}')
+		self.log(f'Adding bootloader {bootloader} to {self.boot_partition}')
 
 		if bootloader == 'systemd-bootctle':
 			o = b''.join(sys_command(f'/usr/bin/arch-chroot {self.mountpoint} bootctl --no-variables --path=/boot install'))
@@ -222,17 +241,17 @@ class Installer():
 	def install_profile(self, profile):
 		profile = Profile(self, profile)
 
-		log(f'Installing network profile {profile}')
+		self.log(f'Installing network profile {profile}')
 		return profile.install()
 
 	def enable_sudo(self, entity :str, group=False):
-		log(f'Enabling sudo permissions for {entity}.')
+		self.log(f'Enabling sudo permissions for {entity}.')
 		with open(f'{self.mountpoint}/etc/sudoers', 'a') as sudoers:
 			sudoers.write(f'{"%" if group else ""}{entity} ALL=(ALL) ALL\n')
 		return True
 
 	def user_create(self, user :str, password=None, groups=[], sudo=False):
-		log(f'Creating user {user}')
+		self.log(f'Creating user {user}')
 		o = b''.join(sys_command(f'/usr/bin/arch-chroot {self.mountpoint} useradd -m -G wheel {user}'))
 		if password:
 			self.user_set_pw(user, password)
@@ -245,7 +264,7 @@ class Installer():
 			self.helper_flags['user'] = True
 
 	def user_set_pw(self, user, password):
-		log(f'Setting password for {user}')
+		self.log(f'Setting password for {user}')
 
 		if user == 'root':
 			# This means the root account isn't locked/disabled with * in /etc/passwd
diff --git a/archinstall/lib/luks.py b/archinstall/lib/luks.py
index d4ee6632..7dfa9edc 100644
--- a/archinstall/lib/luks.py
+++ b/archinstall/lib/luks.py
@@ -2,6 +2,8 @@ import os
 from .exceptions import *
 from .general import *
 from .disk import Partition
+from .output import log, LOG_LEVELS
+from .storage import storage
 
 class luks2():
 	def __init__(self, partition, mountpoint, password, *args, **kwargs):
@@ -22,7 +24,10 @@ class luks2():
 		return True
 
 	def encrypt(self, partition, password, key_size=512, hash_type='sha512', iter_time=10000, key_file=None):
-		log(f'Encrypting {partition}')
+		# TODO: We should be able to integrate this into the main log some how.
+		#       Perhaps post-mortem?
+		log(f'Encrypting {partition}', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
+
 		if not key_file:
 			key_file = f"/tmp/{os.path.basename(self.partition.path)}.disk_pw"  # TODO: Make disk-pw-file randomly unique?
 		if type(password) != bytes: password = bytes(password, 'UTF-8')
diff --git a/archinstall/lib/mirrors.py b/archinstall/lib/mirrors.py
index 1cd53ed0..a92c47e0 100644
--- a/archinstall/lib/mirrors.py
+++ b/archinstall/lib/mirrors.py
@@ -2,6 +2,7 @@ import urllib.request
 
 from .exceptions import *
 from .general import *
+from .output import log
 
 def filter_mirrors_by_region(regions, destination='/etc/pacman.d/mirrorlist', tmp_dir='/root', *args, **kwargs):
 	"""
@@ -57,7 +58,7 @@ def insert_mirrors(mirrors, *args, **kwargs):
 	return True
 
 def use_mirrors(regions :dict, destination='/etc/pacman.d/mirrorlist'):
-	log(f'A new package mirror-list has been created: {destination}')
+	log(f'A new package mirror-list has been created: {destination}', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
 	for region, mirrors in regions.items():
 		with open(destination, 'w') as mirrorlist:
 			for mirror in mirrors:
diff --git a/archinstall/lib/output.py b/archinstall/lib/output.py
index d1b418d9..bba02cd7 100644
--- a/archinstall/lib/output.py
+++ b/archinstall/lib/output.py
@@ -1,4 +1,39 @@
+import abc
+import os
 import sys
+import logging
+
+class LOG_LEVELS:
+	Critical = 0b001
+	Error = 0b010
+	Warning = 0b011
+	Info = 0b101
+	Debug = 0b111
+
+class journald(dict):
+	@abc.abstractmethod
+	def log(message, level=LOG_LEVELS.Debug):
+		import systemd.journal
+		log_adapter = logging.getLogger('archinstall')
+		log_fmt = logging.Formatter("[%(levelname)s]: %(message)s")
+		log_ch = systemd.journal.JournalHandler()
+		log_ch.setFormatter(log_fmt)
+		log_adapter.addHandler(log_ch)
+		log_adapter.setLevel(logging.DEBUG)
+		
+		if level == LOG_LEVELS.Critical:
+			log_adapter.critical(message)
+		elif level == LOG_LEVELS.Error:
+			log_adapter.error(message)
+		elif level == LOG_LEVELS.Warning:
+			log_adapter.warning(message)
+		elif level == LOG_LEVELS.Info:
+			log_adapter.info(message)
+		elif level == LOG_LEVELS.Debug:
+			log_adapter.debug(message)
+		else:
+			# Fallback logger
+			log_adapter.debug(message)
 
 # Found first reference here: https://stackoverflow.com/questions/7445658/how-to-detect-if-the-console-does-support-ansi-escape-codes-in-python
 # And re-used this: https://github.com/django/django/blob/master/django/core/management/color.py#L12
@@ -37,10 +72,45 @@ def stylize_output(text :str, *opts, **kwargs):
 		text = '%s\x1b[%sm' % (text or '', RESET)
 	return '%s%s' % (('\x1b[%sm' % ';'.join(code_list)), text or '')
 
+GLOB_IMP_ERR_NOTIFIED = False
 def log(*args, **kwargs):
-	string = ' '.join([str(x) for x in args])
+	if 'level' in kwargs:
+		try:
+			import archinstall
+			if 'LOG_LEVEL' not in archinstall.storage:
+				archinstall.storage['LOG_LEVEL'] = LOG_LEVELS.Info
+
+			if kwargs['level'] >= archinstall.storage['LOG_LEVEL']:
+				# Level on log message was Debug, but output level is set to Info.
+				# In that case, we'll drop it.
+				return None
+		except ModuleNotFoundError:
+			global GLOB_IMP_ERR_NOTIFIED
+
+			if GLOB_IMP_ERR_NOTIFIED is False:
+				print('[Error] Archinstall not found in global import path. Can not determain log level for log messages.')
+
+			GLOB_IMP_ERR_NOTIFIED = True
+
+	string = orig_string = ' '.join([str(x) for x in args])
+
 	if supports_color():
 		kwargs = {'bg' : 'black', 'fg': 'white', **kwargs}
 		string = stylize_output(string, **kwargs)
 
+	# Log to a file output unless specifically told to suppress this feature.
+	if 'file' in kwargs and not 'suppress' in kwargs and kwargs['suppress']:
+		if type(kwargs['file']) is str:
+			with open(kwargs['file'], 'a') as log_file:
+				log_file.write(f"{orig_string}\n")
+		else:
+			kwargs['file'].write(f"{orig_string}\n")
+
+	# If we assigned a level, try to log it to systemd's journald.
+	if 'level' in kwargs:
+		try:
+			journald.log(string, level=kwargs['level'])
+		except ModuleNotFoundError:
+			pass # Ignore writing to journald
+
 	print(string)
\ No newline at end of file
diff --git a/archinstall/lib/profiles.py b/archinstall/lib/profiles.py
index 322436c0..65ffd243 100644
--- a/archinstall/lib/profiles.py
+++ b/archinstall/lib/profiles.py
@@ -4,6 +4,7 @@ from collections import OrderedDict
 from .general import multisplit, sys_command, log
 from .exceptions import *
 from .networking import *
+from .output import log, LOG_LEVELS
 
 UPSTREAM_URL = 'https://raw.githubusercontent.com/Torxed/archinstall/master/profiles'
 
@@ -117,7 +118,7 @@ class Profile():
 			# TODO: Remove
 			__builtins__['installation'] = self.installer
 			with instructions as runtime:
-				log(f'{self} finished successfully.', bg='black', fg='green')
+				log(f'{self} finished successfully.', bg='black', fg='green', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
 		
 		return True