Aligned log messages, minor general fixes, unified virtual and real filesystems and started to work on the API for parsing NimD's config (also added empty networking module)

README.md

@@ -28,7 +28,7 @@ NimD assumes that the standard file descriptors 0, 1 and 2 (stdin, stdout and st
 know how to check for a proper set of file descriptors and connect them manually, please make a PR, I'd love to hear how to do that.
 
 When mounting the filesystem, NimD is at least somewhat smart:
-- First, it'll try to mount the standard POSIX virtual filesystems (/proc, /sys, etc) if they're not mounted already
+- First, it'll try to mount the standard POSIX virtual filesystems (/proc, /sys, etc) if they're not mounted already (you specify which)
 - Then, it'll parse /etc/fstab and mount all the disks from there as well (unless they are already mounted, of course).
     Drive IDs/UUIDs, LABELs and PARTUUIDs are also supported and are automatically resolved to their respective /dev/disk/by-XXX symlink
 

src/core/config.nim

@@ -0,0 +1,30 @@
+# Copyright 2021 Mattia Giambirtone & All Contributors
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#    http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+import parsecfg
+
+
+import ../util/logging
+import services
+import fs
+
+
+type
+    Config* = ref object
+        ## Configuration object
+        # The desired log verbosity of nimD
+        logLevel*: LogLevel
+        logDir*: Directory
+        services*: tuple[runlevel: RunLevel, services: seq[Service]]
+        filesystems*: seq[Filesystem]

src/core/control.nim

@@ -0,0 +1,13 @@
+# Copyright 2021 Mattia Giambirtone & All Contributors
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#    http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.

src/core/fs.nim

@@ -56,11 +56,12 @@ type
         data: string
         dump: uint8
         pass: uint8
+        virtual: bool   # Is this a virtual filesystem?
 
 
-proc newFilesystem*(source, target, fstype: string, mountflags: uint64 = 0, data: string = "", dump: uint8 = 0, pass: uint8 = 0): Filesystem =
+proc newFilesystem*(source, target, fstype: string, mountflags: uint64 = 0, data: string = "", dump: uint8 = 0, pass: uint8 = 0, virtual: bool = false): Filesystem =
     ## Initializes a new filesystem object
-    result = Filesystem(source: source, target: target, fstype: fstype, mountflags: mountflags, data: data, dump: dump, pass: pass)
+    result = Filesystem(source: source, target: target, fstype: fstype, mountflags: mountflags, data: data, dump: dump, pass: pass, virtual: virtual)
 
 
 proc newSymlink*(source, dest: string): Symlink =
@@ -73,10 +74,13 @@ proc newDirectory*(path: string, permissions: uint64): Directory =
     result = Directory(path: path, permissions: permissions)
 
 
-# Stores VFS entries to be mounted upon boot (usually /proc, /sys, etc). You could
+# Stores filesystem entries to be mounted upon boot. You could do this with a oneshot
-# do this with a oneshot service, but it's a simple enough feature to have it built-in
+# service, but it's a simple enough feature to have it built-in into the init itself, 
-# into the init itself (especially since it makes error handling a heck of a lot easier)
+# especially since it makes error handling a heck of a lot easier.
-var virtualFileSystems: seq[Filesystem] = @[]
+# Note this has to be used only for stuff that's not already in /etc/fstab, like virtual
+# filesystems (/proc, /sys, etc) if your kernel doesn't already mount them upon startup
+# (which it most likely does)
+var fileSystems: seq[Filesystem] = @[]
 # Since creating symlinks is a pretty typical operation for an init, NimD
 # provides a straightforward way to create them on boot without creating
 # full fledged oneshot services 
@@ -86,38 +90,38 @@ var symlinks: seq[Symlink ] = @[]
 var directories: seq[Directory] = @[]
 
 
-proc addVFS*(filesystem: FileSystem) =
+proc addFS*(filesystem: FileSystem) =
-    ## Adds a virtual filesystem to be mounted upon boot
+    ## Adds a filesystem to be mounted upon boot
-    virtualFileSystems.add(filesystem)
+    filesystems.add(filesystem)
 
 
-proc removeVFS*(filesystem: Filesystem) =
+proc removeFS*(filesystem: Filesystem) =
-    ## Removes a virtual filesystem. Note
+    ## Unregisters a filesystem. Note
     ## this has no effect if executed after
-    ## the VFSs have been mounted (i.e. after
+    ## the filesystems have been mounted (i.e. after
-    ## a call to mountVirtualDisks)
+    ## a call to mountDisks)
-    for i, f in virtualFileSystems:
+    for i, f in filesystems:
         if f == filesystem:
-            virtualFileSystems.del(i)
+            filesystems.del(i)
 
 
-iterator getAllVFSPaths: string =
+iterator getAllFSPaths: string =
     ## Yields all of the mount points of
-    ## the currently registered virtual
+    ## the currently registered
     ## filesystems
-    for vfs in virtualFileSystems:
+    for fs in filesystems:
-        yield vfs.target
+        yield fs.target
 
 
-iterator getAllVFSNames: string =
+iterator getAllFSNames: string =
     ## This is similar to what
     ## getAllVFSPaths does, except
     ## it yields the VFS' source
     ## instead of the mount point 
     ## (which in this case is just
     ## an alias, hence the "names" part)
-    for vfs in virtualFileSystems:
+    for fs in filesystems:
-        yield vfs.source
+        yield fs.source
 
 
 proc addSymlink*(symlink: Symlink) =
@@ -231,12 +235,13 @@ proc checkDiskIsMounted(search: Filesystem, expand: bool = false): bool =
     return false
 
 
-proc mountRealDisks*(logger: Logger, fstab: string = "/etc/fstab") =
+proc mountDisks*(logger: Logger, fstab: string = "/etc/fstab") =
-    ## Mounts real disks from /etc/fstab
+    ## Mounts disks from /etc/fstab as well as the ones registered
+    ## via addFS (these are mounted first)
     var retcode = 0
     try:
-        logger.debug(&"Reading disk entries from {fstab}")
+        logger.debug(&"Reading disk entries from {fstab} (mounting custom filesystems first!)")
-        for entry in parseFileSystemTable(readFile(fstab)):
+        for entry in filesystems & parseFileSystemTable(readFile(fstab)):
             if checkDiskIsMounted(entry, expand=true):
                 logger.debug(&"Skipping mounting filesystem {entry.source} ({entry.fstype}) at {entry.target}: already mounted")
                 continue
@@ -255,28 +260,6 @@ proc mountRealDisks*(logger: Logger, fstab: string = "/etc/fstab") =
         nimDExit(logger, 131)
 
 
-proc mountVirtualDisks*(logger: Logger) =
-    ## Mounts POSIX virtual filesystems/partitions,
-    ## such as /proc and /sys
-    var retcode = 0
-    for entry in virtualFileSystems:
-        if checkDiskIsMounted(entry):
-            logger.debug(&"Skipping mounting filesystem {entry.source} ({entry.fstype}) at {entry.target}: already mounted")
-            continue
-        logger.debug(&"Mounting filesystem {entry.source} ({entry.fstype}) at {entry.target} with mount option(s) {entry.data}")
-        logger.trace(&"Calling mount('{entry.source}', '{entry.target}', '{entry.fstype}', {entry.mountflags}, '{entry.data}')")
-        retcode = mount(entry.source, entry.target, entry.fstype, entry.mountflags, entry.data)
-        logger.trace(&"mount('{entry.source}', '{entry.target}', '{entry.fstype}', {entry.mountflags}, '{entry.data}') returned {retcode}")
-        if retcode == -1:
-            logger.error(&"Mounting disk {entry.source} at {entry.target} has failed with error {posix.errno}: {posix.strerror(posix.errno)}")
-            # Resets the error code
-            posix.errno = cint(0)
-            logger.fatal("Failed mounting vital system disk partition, system is likely corrupted, booting cannot continue")
-            nimDExit(logger, 131) # ENOTRECOVERABLE - State not recoverable
-        else:
-            logger.debug(&"Mounted {entry.source} at {entry.target}")
-
-
 proc unmountAllDisks*(logger: Logger, code: int) =
     ## Unmounts all currently mounted disks, including the ones that
     ## were not mounted trough fstab but excluding virtual filesystems
@@ -293,13 +276,16 @@ proc unmountAllDisks*(logger: Logger, code: int) =
             # as they are critical system components (especially /proc): maybe we should use stat()
             # instead and make a generic check, but adding a system call into the mix seems overkill given
             # we alredy have all the info we need
-            if entry in virtualFileSystems:
+            if entry.virtual:
+                # Detects VFS manually
                 continue
-            for source in getAllVFSNames():
+            for source in getAllFSNames():
+                # Detects VFS by name
                 if entry.source == source:
                     isVFS = true
                     break
-            for path in getAllVFSPaths():
+            for path in getAllFSPaths():
+                # Detects VFS by mount point
                 if entry.target.startswith(path):
                     isVFS = true
                     break

src/core/services.nim

@@ -12,6 +12,7 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 import strformat
+import strutils
 import cpuinfo
 import tables
 import osproc
@@ -112,8 +113,10 @@ proc supervisorWorker(logger: Logger, service: Service, pid: int) =
     var returnCode: int
     var sig: int
     var process: Process
+    logger.debug("Switching logs to file")
     logger.switchToFile()
     while true:
+        logger.trace(&"Calling waitpid() on {pid}")
         returnCode = posix.waitPid(cint(pid), status, WUNTRACED)
         if WIFEXITED(status):
             sig = 0
@@ -121,6 +124,7 @@ proc supervisorWorker(logger: Logger, service: Service, pid: int) =
             sig = WTERMSIG(status)
         else:
             sig = -1
+        logger.trace(&"Call to waitpid() set status to {status} and returned {returnCode}, setting sig to {sig}")
         case service.restart:
             of Never:
                 logger.info(&"Service '{service.name}' ({returnCode}) has exited, shutting down controlling process")
@@ -165,7 +169,9 @@ proc startService(logger: Logger, service: Service) =
     ## Starts a single service (this is called by
     ## startServices below until all services have
     ## been started). This function is supposed to 
-    ## be called from a forked process!
+    ## be called from a forked process and it itself
+    ## forks to call supervisorWorker if the service
+    ## is a supervised one
     var process: Process
     try:
         var split = shlex(service.exec)
@@ -179,6 +185,7 @@ proc startService(logger: Logger, service: Service) =
         if service.supervised:
             var pid = posix.fork()
             if pid == 0:
+                logger.trace(&"New child has been spawned")
                 supervisorWorker(logger, service, process.processID)
         # If the service is unsupervised we just exit
     except:
@@ -192,7 +199,7 @@ proc startServices*(logger: Logger, level: RunLevel, workers: int = 1) =
     ## Starts the registered services in the 
     ## given runlevel
     if workers > cpuinfo.countProcessors():
-        logger.warning(&"The configured number of workers ({workers}) is greater than the recommended one ({cpuinfo.countProcessors()}), performance may degrade")
+        logger.warning(&"The configured number of workers ({workers}) is greater than the number of CPU cores ({cpuinfo.countProcessors()}), performance may degrade")
     var workerCount: int = 0
     var status: cint
     var pid: int = posix.fork()
@@ -206,7 +213,10 @@ proc startServices*(logger: Logger, level: RunLevel, workers: int = 1) =
                 servicesCopy.add(service)
         while servicesCopy.len() > 0:
             if workerCount == workers:
-                discard waitPid(cint(pid), status, WUNTRACED)
+                logger.debug(&"Worker queue full, waiting for some worker to exit...")
+                logger.trace(&"Calling waitpid() on {pid}")
+                var returnCode = waitPid(cint(pid), status, WUNTRACED)
+                logger.trace(&"Call to waitpid() set status to {status} and returned {returnCode}")
                 dec(workerCount)
             pid = posix.fork()
             if pid == -1:
@@ -225,4 +235,7 @@ proc startServices*(logger: Logger, level: RunLevel, workers: int = 1) =
                 servicesCopy.del(0)
         quit(0)
     else:
-        discard waitPid(cint(pid), status, WUNTRACED)
+        logger.debug(&"Waiting for completion of service spawning in runlevel {($level).toLowerAscii()}")
+        logger.trace(&"Calling waitpid() on {pid}")
+        var returnCode = waitPid(cint(pid), status, WUNTRACED)
+        logger.trace(&"Call to waitpid() set status to {status} and returned {returnCode}")

src/main.nim

@@ -40,12 +40,12 @@ proc addStuff =
     addSymlink(newSymlink(dest="/dev/std/in", source="/proc/self/fd/0"))   # Should say link already exists
     # Adds virtual filesystems (Update: apparently the kernel already mounts this stuff!)
     #[
-    addVFS(newFilesystem(source="proc", target="/proc", fstype="proc", mountflags=0u64, data="nosuid,noexec,nodev", dump=0u8, pass=0u8))
+    addFS(newFilesystem(source="proc", target="/proc", fstype="proc", mountflags=0u64, data="nosuid,noexec,nodev", dump=0u8, pass=0u8))
-    addVFS(newFilesystem(source="sys", target="/sys", fstype="sysfs", mountflags=0u64, data="nosuid,noexec,nodev", dump=0u8, pass=0u8))
+    addFS(newFilesystem(source="sys", target="/sys", fstype="sysfs", mountflags=0u64, data="nosuid,noexec,nodev", dump=0u8, pass=0u8))
-    addVFS(newFilesystem(source="run", target="/run", fstype="tmpfs", mountflags=0u64, data="mode=0755,nosuid,nodev", dump=0u8, pass=0u8))
+    addFS(newFilesystem(source="run", target="/run", fstype="tmpfs", mountflags=0u64, data="mode=0755,nosuid,nodev", dump=0u8, pass=0u8))
-    addVFS(newFilesystem(source="dev", target="/dev", fstype="devtmpfs", mountflags=0u64, data="mode=0755,nosuid", dump=0u8, pass=0u8))
+    addFS(newFilesystem(source="dev", target="/dev", fstype="devtmpfs", mountflags=0u64, data="mode=0755,nosuid", dump=0u8, pass=0u8))
-    addVFS(newFilesystem(source="devpts", target="/dev/pts", fstype="devpts", mountflags=0u64, data="mode=0620,gid=5,nosuid,noexec", dump=0u8, pass=0u8))
+    addFS(newFilesystem(source="devpts", target="/dev/pts", fstype="devpts", mountflags=0u64, data="mode=0620,gid=5,nosuid,noexec", dump=0u8, pass=0u8))
-    addVFS(newFilesystem(source="shm", target="/dev/shm", fstype="tmpfs", mountflags=0u64, data="mode=1777,nosuid,nodev", dump=0u8, pass=0u8))
+    addFS(newFilesystem(source="shm", target="/dev/shm", fstype="tmpfs", mountflags=0u64, data="mode=1777,nosuid,nodev", dump=0u8, pass=0u8))
     ]#
     addDirectory(newDirectory("test", 777))           # Should create a directory
     addDirectory(newDirectory("/dev/disk", 123))      # Should say directory already exists
@@ -72,7 +72,7 @@ proc addStuff =
 proc main(logger: Logger, mountDisks: bool = true, fstab: string = "/etc/fstab") = 
     ## NimD's entry point and setup
     ## function
-    logger.debug("Starting NimD: A minimal, self-contained dependency-based Linux init system written in Nim")
+    logger.debug("Starting NimD: A minimal, self-contained, dependency-based Linux init system written in Nim")
     logger.info(&"NimD version {NimdVersion.major}.{NimdVersion.minor}.{NimdVersion.patch} is starting up!")
     logger.trace("Calling getCurrentProcessId()")
     let pid = getCurrentProcessId()
@@ -84,15 +84,12 @@ proc main(logger: Logger, mountDisks: bool = true, fstab: string = "/etc/fstab")
     logger.trace(&"getuid() returned {uid}")
     if uid != 0:
         logger.fatal(&"NimD must run as root, but current user id is {uid}")
-        nimDExit(logger, EPERM)   # EPERM - Operation not permitted
+        nimDExit(logger, EPERM, emerg=false)   # EPERM - Operation not permitted
     logger.trace("Setting up signal handlers")
     onSignal(SIGABRT, SIGALRM, SIGHUP, SIGILL, SIGKILL, SIGQUIT, SIGSTOP, SIGSEGV, SIGTSTP,
             SIGTRAP, SIGPIPE, SIGUSR1, SIGUSR2, 6, SIGFPE, SIGBUS, SIGURG, SIGTERM, SIGINT):  # 6 is SIGIOT
         # Can't capture local variables because this implicitly generates
-        # a noconv procedure, so we use getDefaultLogger() instead. Must find
+        # a noconv procedure, so we use getDefaultLogger() instead
-        # a better solution long-term because we need the configuration from
-        # our own logger object (otherwise we'd always create a new one and
-        # never switch our logs to file once booting is completed)
         getDefaultLogger().warning(&"Ignoring signal {sig} ({strsignal(sig)})")  # Nim injects the variable "sig" into the scope. Gotta love those macros
     onSignal(SIGCHLD):
         # One of the key features of an init system is reaping child
@@ -102,10 +99,7 @@ proc main(logger: Logger, mountDisks: bool = true, fstab: string = "/etc/fstab")
     try:
         if mountDisks:
             logger.info("Mounting filesystem")
-            logger.info("Mounting virtual disks")
+            mountDisks(logger, fstab)
-            mountVirtualDisks(logger)
-            logger.info("Mounting real disks")
-            mountRealDisks(logger, fstab)
         else:
             logger.info("Skipping disk mounting, assuming this has already been done")
         logger.info("Creating symlinks")

src/util/logging.nim

@@ -38,8 +38,8 @@ type
         level*: LogLevel
         handlers*: seq[LogHandler]
 
-const defaultLevel = LogLevel.Info
+var defaultLevel = LogLevel.Info
-const logFile = "/var/log/nimd"
+var logFile = "/var/log/nimd"
 var logToFile: bool = false
 
 
@@ -58,8 +58,12 @@ proc fatal*(self: Logger, message: string) = self.log(LogLevel.Fatal, message)
 proc newLogger*(level: LogLevel = defaultLevel, handlers: seq[LogHandler] = @[]): Logger = Logger(level: level, handlers: handlers)
 proc setLevel*(self: Logger, level: LogLevel) = self.level = level
 proc getLevel*(self: Logger): LogLevel = self.level
+proc setLogFile*(filename: string) = logFile = filename
+proc getLogFile*: string = logFile
+proc setDefaultLevel*(level: LogLevel) = defaultLevel = level
+proc getDefaultLevel*: LogLevel = defaultLevel
 proc createHandler*(procedure: proc (self: LogHandler, logger: Logger, message: string), level: LogLevel): LogHandler = LogHandler(code: procedure, level: level)
-proc createStreamHandler*(procedure: proc (self: LogHandler, logger: Logger, message: string), level: LogLevel, filename: string): StreamHandler = StreamHandler(code: procedure, level: level, filename: filename, file: open(filename, fmWrite))
+proc createStreamHandler*(procedure: proc (self: LogHandler, logger: Logger, message: string), level: LogLevel, filename: string): StreamHandler = StreamHandler(code: procedure, level: level, filename: filename, file: open(filename, fmAppend))
 proc addHandler*(self: Logger, handler: LogHandler) = self.handlers.add(handler)
 proc removeHandler*(self: Logger, handler: LogHandler) = self.handlers.delete(self.handlers.find(handler))
 
@@ -71,84 +75,99 @@ proc log(self: Logger, level: LogLevel = defaultLevel, message: string) =
             handler.code(handler, self, message)
 
 
+# Note: Log messages have been *carefully* hand tuned to be perfectly aligned both in the console and in log files.
+# Do NOT touch the alignment offsets or your console output and logs will look like trash
+
+
 proc logTraceStderr(self: LogHandler, logger: Logger, message: string) =
     setForegroundColor(fgMagenta)
-    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - TRACE ({posix.getpid()})] {message}""")
+    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} TRACE {"-":>3} ({posix.getpid():03})] {message}""")
     stderr.flushFile()
     setForegroundColor(fgDefault)
 
 
 proc logDebugStderr(self: LogHandler, logger: Logger, message: string) =
     setForegroundColor(fgCyan)
-    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - DEBUG ({posix.getpid()})] {message}""")
+    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} DEBUG {"-":>3} ({posix.getpid():03})] {message}""")
     stderr.flushFile()
     setForegroundColor(fgDefault)
 
 
 proc logInfoStderr(self: LogHandler, logger: Logger, message: string) =
     setForegroundColor(fgGreen)
-    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - INFO ({posix.getpid()})] {message}""")
+    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} INFO {"-":>4} ({posix.getpid():03})] {message}""")
     stderr.flushFile()
     setForegroundColor(fgDefault)
 
 
 proc logWarningStderr(self: LogHandler, logger: Logger, message: string) =
     setForegroundColor(fgYellow)
-    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - WARNING ({posix.getpid()})] {message}""")
+    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} WARNING {"-":>1} ({posix.getpid():03})] {message}""")
     stderr.flushFile()
     setForegroundColor(fgDefault)
 
 
 proc logErrorStderr(self: LogHandler, logger: Logger, message: string) =
     setForegroundColor(fgRed)
-    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - ERROR ({posix.getpid()})] {message}""")
+    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} ERROR {"-":>3} ({posix.getpid():03})] {message}""")
     stderr.flushFile()
     setForegroundColor(fgDefault)
 
 
 proc logCriticalStderr(self: LogHandler, logger: Logger, message: string) =
-    setForegroundColor(fgRed)
+    setForegroundColor(fgYellow)
-    stderr.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - CRITICAL ({posix.getpid()})] {message}""")
+    setBackgroundColor(bgRed)
-    stderr.flushFile()
+    stderr.write(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<4} {"-":>1} CRITICAL {"-":>2} ({posix.getpid():03})]""")
+    setBackgroundColor(bgDefault)
+    stderr.writeLine(&""" {message}""")
     setForegroundColor(fgDefault)
+    stderr.flushFile()
 
 
 proc logFatalStderr(self: LogHandler, logger: Logger, message: string) =
     setForegroundColor(fgBlack)
     setBackgroundColor(bgRed)
-    stderr.write(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - FATAL ({posix.getpid()})]""")
+    stderr.write(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<5} {"-":>1} {"":>1} FATAL {"-":>3} ({posix.getpid():03})]""")
     setForegroundColor(fgRed)
     setBackgroundColor(bgDefault)
-    stderr.writeline(&" {message}")
+    stderr.writeline(&""" {message}""")
     setForegroundColor(fgDefault)
     stderr.flushFile()
 
 
 proc logTraceFile(self: LogHandler, logger: Logger, message: string) =
-    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - TRACE ({posix.getpid()})] {message}""")
+    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} TRACE {"-":>3} ({posix.getpid():03})] {message}""")
+    StreamHandler(self).file.flushFile()
 
 
 proc logDebugFile(self: LogHandler, logger: Logger, message: string) =
-    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - TRACE ({posix.getpid()})] {message}""")
+    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} DEBUG {"-":>3} ({posix.getpid():03})] {message}""")
+    StreamHandler(self).file.flushFile()
 
 
 proc logInfoFile(self: LogHandler, logger: Logger, message: string) =
-    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - TRACE ({posix.getpid()})] {message}""")
+    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} INFO {"-":>4} ({posix.getpid():03})] {message}""")
+    StreamHandler(self).file.flushFile()
 
 
 proc logWarningFile(self: LogHandler, logger: Logger, message: string) =
-    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - TRACE ({posix.getpid()})] {message}""")
+    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} WARNING {"-":>1} ({posix.getpid():03})] {message}""")
+    StreamHandler(self).file.flushFile()
+
 
 proc logErrorFile(self: LogHandler, logger: Logger, message: string) =
-    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - TRACE ({posix.getpid()})] {message}""")
+    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<10} {"-":>1} {"":>1} ERROR {"-":>3} ({posix.getpid():03})] {message}""")
+    StreamHandler(self).file.flushFile()
 
 
 proc logCriticalFile(self: LogHandler, logger: Logger, message: string) =
-    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - TRACE ({posix.getpid()})] {message}""")
+    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<4} {"-":>1} CRITICAL {"-":>2} ({posix.getpid():03})] {message}""")
+    StreamHandler(self).file.flushFile()
 
 
 proc logFatalFile(self: LogHandler, logger: Logger, message: string) =
-    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss")} - TRACE ({posix.getpid()})] {message}""")
+    StreamHandler(self).file.writeLine(&"""[{fromUnix(getTime().toUnixFloat().int).format("d/M/yyyy HH:mm:ss"):<5} {"-":>1} {"":>1} FATAL {"-":>3} ({posix.getpid():03})] {message}""")
+    StreamHandler(self).file.flushFile()
 
 
 proc switchToFile*(self: Logger) =
@@ -158,7 +177,7 @@ proc switchToFile*(self: Logger) =
     if logToFile:
         return
     logToFile = true
-    self.handlers = @[]
+    self.handlers = @[]   # Don't you love it when you can just let the GC manage memory for you?
     self.addHandler(createStreamHandler(logTraceFile, LogLevel.Trace, logFile))
     self.addHandler(createStreamHandler(logDebugFile, LogLevel.Debug, logFile))
     self.addHandler(createStreamHandler(logInfoFile, LogLevel.Info, logFile))
@@ -168,6 +187,23 @@ proc switchToFile*(self: Logger) =
     self.addHandler(createStreamHandler(logFatalFile, LogLevel.Fatal, logFile))
 
 
+proc switchToConsole*(self: Logger) =
+    ## Switches logging to the console and
+    ## changes the behavior of getDefaultLogger
+    ## accordingly
+    if not logToFile:
+        return
+    logToFile = false
+    self.handlers = @[]
+    self.addHandler(createHandler(logTraceStderr, LogLevel.Trace))
+    self.addHandler(createHandler(logDebugStderr, LogLevel.Debug))
+    self.addHandler(createHandler(logInfoStderr, LogLevel.Info))
+    self.addHandler(createHandler(logWarningStderr, LogLevel.Warning))
+    self.addHandler(createHandler(logErrorStderr, LogLevel.Error))
+    self.addHandler(createHandler(logCriticalStderr, LogLevel.Critical))
+    self.addHandler(createHandler(logFatalStderr, LogLevel.Fatal))
+
+
 proc getDefaultLogger*(): Logger =
     ## Gets a simple logger with level set
     ## to LogLevel.Info and one handler per

src/util/misc.nim

@@ -78,7 +78,9 @@ proc reapProcess*(logger: Logger) =
     ## and restarts them as needed
     logger.debug("Handling SIGCHLD")
     var status: cint
-    discard posix.waitPid(-1, status, WNOHANG)   # This doesn't hang, which is what we want
+    logger.trace("Calling waitpid() on -1")
+    var returnCode = posix.waitPid(-1, status, WNOHANG)   # This doesn't hang, which is what we want
+    logger.trace(&"Call to waitpid() set status to {status} and returned {returnCode}")
 
 
 proc exists*(p: string): bool =