Merge pull request #95 from Torxed/improved-logging

Tested and verified on a installation. Log file ends up and on errors there's a message printing guiding users to look for it and report issues :)

7 files changed, 72 insertions, 38 deletions

diff --git a/archinstall/lib/disk.py b/archinstall/lib/disk.py
index e9fa12a0..c14cb48c 100644
--- a/archinstall/lib/disk.py
+++ b/archinstall/lib/disk.py
@@ -119,7 +119,7 @@ class Partition():
 			return f'Partition(path={self.path}, fs={self.filesystem}, mounted={self.mountpoint})'
 
 	def format(self, filesystem):
-		log(f'Formatting {self} -> {filesystem}', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
+		log(f'Formatting {self} -> {filesystem}', level=LOG_LEVELS.Info)
 		if filesystem == 'btrfs':
 			o = b''.join(sys_command(f'/usr/bin/mkfs.btrfs -f {self.path}'))
 			if b'UUID' not in o:
@@ -162,7 +162,7 @@ class Partition():
 
 	def mount(self, target, fs=None, options=''):
 		if not self.mountpoint:
-			log(f'Mounting {self} to {target}', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
+			log(f'Mounting {self} to {target}', level=LOG_LEVELS.Info)
 			if not fs:
 				if not self.filesystem: raise DiskError(f'Need to format (or define) the filesystem on {self} before mounting.')
 				fs = self.filesystem
@@ -227,7 +227,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}', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
+		log(f'Adding partition to {self.blockdevice}', level=LOG_LEVELS.Info)
 		
 		previous_partitions = self.blockdevice.partitions
 		if format:
diff --git a/archinstall/lib/general.py b/archinstall/lib/general.py
index 203f5fa9..dc94b063 100644
--- a/archinstall/lib/general.py
+++ b/archinstall/lib/general.py
@@ -245,9 +245,9 @@ class sys_command():#Thread):
 			self.exit_code = 0
 
 		if self.exit_code != 0 and not self.kwargs['suppress_errors']:
-			self.log(f"'{self.raw_cmd}' did not exit gracefully, exit code {self.exit_code}.", level=LOG_LEVELS.Error)
-			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.log(self.trace_log.decode('UTF-8'), level=LOG_LEVELS.Debug)
+			#self.log(f"'{self.raw_cmd}' did not exit gracefully, exit code {self.exit_code}.", level=LOG_LEVELS.Error)
+			raise SysCallError(f"{self.trace_log.decode('UTF-8')}\n'{self.raw_cmd}' did not exit gracefully (trace log above), exit code: {self.exit_code}")
 
 		self.ended = time.time()
 		with open(f'{self.cwd}/trace.log', 'wb') as fh:
diff --git a/archinstall/lib/installer.py b/archinstall/lib/installer.py
index c9d7e9cc..c4cdf857 100644
--- a/archinstall/lib/installer.py
+++ b/archinstall/lib/installer.py
@@ -34,13 +34,18 @@ class Installer():
 	:type hostname: str, optional
 
 	"""
-	def __init__(self, partition, boot_partition, *, base_packages='base base-devel linux linux-firmware efibootmgr nano', profile=None, mountpoint='/mnt', hostname='ArchInstalled'):
+	def __init__(self, partition, boot_partition, *, base_packages='base base-devel linux linux-firmware efibootmgr nano', profile=None, mountpoint='/mnt', hostname='ArchInstalled', logdir=None, logfile=None):
 		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])
 
+		if logdir:
+			storage['LOG_PATH'] = logdir
+		if logfile:
+			storage['LOG_FILE'] = logfile
+
 		self.helper_flags = {
 			'bootloader' : False,
 			'base' : False,
@@ -54,18 +59,12 @@ class Installer():
 		self.partition = partition
 		self.boot_partition = boot_partition
 
-	def log(self, *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(*args, level=level, file=file, **kwargs)
+	def log(self, *args, level=LOG_LEVELS.Debug, **kwargs):
+		"""
+		installer.log() wraps output.log() mainly to set a default log-level for this install session.
+		Any manual override can be done per log() call.
+		"""
+		log(*args, level=level, **kwargs)
 
 	def __enter__(self, *args, **kwargs):
 		self.partition.mount(self.mountpoint)
@@ -76,13 +75,24 @@ class Installer():
 	def __exit__(self, *args, **kwargs):
 		# b''.join(sys_command(f'sync')) # No need to, since the underlaying fs() object will call sync.
 		# TODO: https://stackoverflow.com/questions/28157929/how-to-safely-handle-an-exception-inside-a-context-manager
+
 		if len(args) >= 2 and args[1]:
+			#self.log(self.trace_log.decode('UTF-8'), level=LOG_LEVELS.Debug)
+			self.log(args[1], level=LOG_LEVELS.Error)
+
+			self.sync_log_to_install_medium()
+
+			# We avoid printing /mnt/<log path> because that might confuse people if they note it down
+			# and then reboot, and a identical log file will be found in the ISO medium anyway.
+			print(f"[!] A log file has been created here: {os.path.join(storage['LOG_PATH'], storage['LOG_FILE'])}")
+			print(f"    Please submit this issue (and file) to https://github.com/Torxed/archinstall/issues")
 			raise args[1]
 
 		self.genfstab()
 
 		if not (missing_steps := self.post_install_check()):
 			self.log('Installation completed without any errors. You may now reboot.', bg='black', fg='green', level=LOG_LEVELS.Info)
+			self.sync_log_to_install_medium()
 			return True
 		else:
 			self.log('Some required steps were not successfully installed/configured before leaving the installer:', bg='black', fg='red', level=LOG_LEVELS.Warning)
@@ -90,8 +100,23 @@ class Installer():
 				self.log(f' - {step}', bg='black', fg='red', level=LOG_LEVELS.Warning)
 			self.log(f"Detailed error logs can be found at: {log_path}", level=LOG_LEVELS.Warning)
 			self.log(f"Submit this zip file as an issue to https://github.com/Torxed/archinstall/issues", level=LOG_LEVELS.Warning)
+			self.sync_log_to_install_medium()
 			return False
 
+	def sync_log_to_install_medium(self):
+		# Copy over the install log (if there is one) to the install medium if
+		# at least the base has been strapped in, otherwise we won't have a filesystem/structure to copy to.
+		if self.helper_flags.get('base-strapped', False) is True:
+			if (filename := storage.get('LOG_FILE', None)):
+				absolute_logfile = os.path.join(storage.get('LOG_PATH', './'), filename)
+
+				if not os.path.isdir(f"{self.mountpoint}/{os.path.dirname(absolute_logfile)}"):
+					os.makedirs(f"{self.mountpoint}/{os.path.dirname(absolute_logfile)}")
+				
+				shutil.copy2(absolute_logfile, f"{self.mountpoint}/{absolute_logfile}")
+
+		return True
+
 	def mount(self, partition, mountpoint, create_mountpoint=True):
 		if create_mountpoint and not os.path.isdir(f'{self.mountpoint}{mountpoint}'):
 			os.makedirs(f'{self.mountpoint}{mountpoint}')
@@ -235,6 +260,7 @@ class Installer():
 		if self.partition.filesystem == 'xfs':
 			self.base_packages.append('xfsprogs')
 		self.pacstrap(self.base_packages)
+		self.helper_flags['base-strapped'] = True
 		#self.genfstab()
 
 		with open(f"{self.mountpoint}/etc/fstab", "a") as fstab:
diff --git a/archinstall/lib/luks.py b/archinstall/lib/luks.py
index 7dfa9edc..e1f14bab 100644
--- a/archinstall/lib/luks.py
+++ b/archinstall/lib/luks.py
@@ -26,7 +26,7 @@ class luks2():
 	def encrypt(self, partition, password, key_size=512, hash_type='sha512', iter_time=10000, key_file=None):
 		# 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))
+		log(f'Encrypting {partition} (This might take a while)', level=LOG_LEVELS.Info)
 
 		if not key_file:
 			key_file = f"/tmp/{os.path.basename(self.partition.path)}.disk_pw"  # TODO: Make disk-pw-file randomly unique?
diff --git a/archinstall/lib/mirrors.py b/archinstall/lib/mirrors.py
index 6649ebfd..d7d35782 100644
--- a/archinstall/lib/mirrors.py
+++ b/archinstall/lib/mirrors.py
@@ -59,7 +59,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}', level=LOG_LEVELS.Info, file=storage.get('logfile', None))
+	log(f'A new package mirror-list has been created: {destination}', level=LOG_LEVELS.Info)
 	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 3c1b12e2..956ad0c4 100644
--- a/archinstall/lib/output.py
+++ b/archinstall/lib/output.py
@@ -2,6 +2,7 @@ import abc
 import os
 import sys
 import logging
+from pathlib import Path
 from .storage import storage
 
 class LOG_LEVELS:
@@ -36,6 +37,11 @@ class journald(dict):
 			# Fallback logger
 			log_adapter.debug(message)
 
+# TODO: Replace log() for session based logging.
+class SessionLogging():
+	def __init__(self):
+		pass
+
 # 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
 def supports_color():
@@ -76,30 +82,28 @@ def stylize_output(text :str, *opts, **kwargs):
 def log(*args, **kwargs):
 	string = orig_string = ' '.join([str(x) for x in args])
 
+	# Attempt to colorize the output if supported
+	# Insert default colors and override with **kwargs
 	if supports_color():
 		kwargs = {'bg' : 'black', 'fg': 'white', **kwargs}
 		string = stylize_output(string, **kwargs)
 
-	if (logfile := storage.get('logfile', None)) and 'file' not in kwargs:
-		kwargs['file'] = logfile
+	# If a logfile is defined in storage,
+	# we use that one to output everything
+	if (filename := storage.get('LOG_FILE', None)):
+		absolute_logfile = os.path.join(storage.get('LOG_PATH', './'), filename)
+		if not os.path.isfile(absolute_logfile):
+			os.makedirs(os.path.dirname(absolute_logfile))
+			Path(absolute_logfile).touch() # Overkill?
 
-	# Log to a file output unless specifically told to suppress this feature.
-	# (level has no effect on the log file, everything will be written there)
-	if 'file' in kwargs and ('suppress' not in kwargs or kwargs['suppress'] == False):
-		if type(kwargs['file']) is str:
-			with open(kwargs['file'], 'a') as log_file:
-				log_file.write(f"{orig_string}\n")
-		elif kwargs['file']:
-			kwargs['file'].write(f"{orig_string}\n")
+		with open(absolute_logfile, 'a') as log_file:
+			log_file.write(f"{orig_string}\n")
 
 	# If we assigned a level, try to log it to systemd's journald.
 	# Unless the level is higher than we've decided to output interactively.
 	# (Remember, log files still get *ALL* the output despite level restrictions)
 	if 'level' in kwargs:
-		if 'LOG_LEVEL' not in storage:
-			storage['LOG_LEVEL'] = LOG_LEVELS.Info
-
-		if kwargs['level'] > storage['LOG_LEVEL']:
+		if kwargs['level'] > storage.get('LOG_LEVEL', LOG_LEVELS.Info):
 			# Level on log message was Debug, but output level is set to Info.
 			# In that case, we'll drop it.
 			return None
@@ -110,5 +114,7 @@ def log(*args, **kwargs):
 			pass # Ignore writing to journald
 
 	# Finally, print the log unless we skipped it based on level.
-	# And we print the string which may or may not contain color formatting.
-	print(string)
\ No newline at end of file
+	# We use sys.stdout.write()+flush() instead of print() to try and
+	# fix issue #94
+	sys.stdout.write(f"{string}\n")
+	sys.stdout.flush()
\ No newline at end of file
diff --git a/archinstall/lib/storage.py b/archinstall/lib/storage.py
index 3af15153..e881700f 100644
--- a/archinstall/lib/storage.py
+++ b/archinstall/lib/storage.py
@@ -15,5 +15,7 @@ storage = {
 		#os.path.abspath(f'{os.path.dirname(__file__)}/../examples')
 	],
 	'UPSTREAM_URL' : 'https://raw.githubusercontent.com/Torxed/archinstall/master/profiles',
-	'PROFILE_DB' : None # Used in cases when listing profiles is desired, not mandatory for direct profile grabing.
+	'PROFILE_DB' : None, # Used in cases when listing profiles is desired, not mandatory for direct profile grabing.
+	'LOG_PATH' : '/var/log/archinstall',
+	'LOG_FILE' : 'install.log'
 }