Whitepaper Logging - ULJ-Yale/qunexsdk GitHub Wiki
Every QuNex command reports what it did. This paper explains how that works: what a command reports through, where the reports end up, what decides whether anything is written at all, and what a command has to do to take part.
It is written for developers who are about to write or maintain a QuNex command,
and it assumes no previous acquaintance with the logging code. It starts from
what the implementation provides and ends with what the person running qunex
sees as a result.
Two shorter documents sit alongside it. Logging is the working guide — the same material condensed to what you need while writing a command. Developer utilities and classes lists the classes themselves. If you are in a hurry, start there and come back here when you want the whole picture.
Everything described here is the Python implementation, which is where the logging of every QuNex command is decided.
QuNex writes two kinds of log, and they hold different material rather than different amounts of detail.
The runlog is QuNex's own account of one invocation. It carries the call
that was made, the report each session produced, and a closing manifest of how
every call ended. One qunex call, one runlog. It is written in QuNex's
vocabulary, and it answers "what did QuNex do?"
A comlog is the record of one external call — FSL, FreeSurfer, MATLAB, a shell script. It holds that call's raw standard output and standard error, together with the QuNex report lines recorded while the call was running, so it reads as a complete account of that one piece of work. It answers "what did the tool say?"
The relationship between them runs one way. A report line can be echoed into a comlog, so that the comlog carries the context around the tool's output. The tool's output stays in the comlog. That keeps the runlog readable at any scale: a run over a hundred sessions produces a runlog you can still read from top to bottom, with a hundred comlogs behind it holding the detail.
The whole of logging lives in python/qx_utilities/general/log/, in three
modules with distinct jobs:
| Module | What it owns | Principal names |
|---|---|---|
report.py |
how a report reads — the vocabulary and the record model |
ReportLog, SessionLog, log_or_console, action, print_qunex_header
|
context.py |
the log files and their lifecycle |
RunContext, ComContext, log_folder, call_echo, write_failure_status
|
settings.py |
whether and where anything is logged |
LogSettings, resolve_logging, set_active, active
|
Above them sit the drivers, and these are the only places that create a
RunContext: gmri (the dispatcher), general/process.py (which runs
processing commands), general/recipe.py (run_recipe),
general/scheduler.py, general/matlab.py and general/run_bash.py.
general/log imports two things from the rest of the tree,
general.exceptions and general.parsing, and nothing else. Every other part
of QuNex is free to import it.
This is a rule with an enforcement: python/tests/test_log_is_a_leaf.py reads
the package's syntax tree and fails if an import of anything else appears —
including one written inside a function body, which is a shape that would
otherwise slip past a reader.
The rule shows up in two places you will meet immediately.
The run and check helpers are called where they live. Running an external
command, checking that a file arrived, linking or copying data are things a run
does, and their return value steers what the command does next. They belong to
processing/core.py and general/core.py, and they accept the log as a
trailing keyword argument:
# check that the T1w image is there; `status` is False when it is missing,
# and either message is recorded in the report through the log we pass in
status = pc.check_for_file(f["t1"], "present", "missing", _log=log)
# copy or link a file, recording the outcome in the same report
gc.link_or_copy(source, target, _log=log)What the log package needs from the tree is handed to it. For example,
comlog_folder is given a log folder and appends comlogs to it, and the study
layout is worked out by the caller, which is where that knowledge lives.
A ReportLog keeps its report as a list of (depth, severity, message)
records, and renders them to text when the text is asked for. A call site states
what a line is; the log decides how it is spelled.
Rendering a record is a single expression:
"\n" + " " * depth + PREFIX[severity] + messageBecause severity and nesting are stored rather than baked into a string, they remain available afterwards. That is what allows the log to count its own errors and derive a command's status from them, and it leaves the door open for other renderings of the same report — an errors-only digest, a machine-readable form — without any call site changing.
| Method | The line it produces | Reach for it when |
|---|---|---|
step(msg) |
---> msg |
a processing step is starting, and the user is waiting on it |
detail(msg) |
... msg |
you are adding a particular of the step above — one file found, one thing copied |
warning(msg) |
---> WARNING: msg |
the run carries on, and the user should know |
error(msg) |
---> ERROR: msg |
something failed. This also counts — see below |
info(msg) |
msg |
you want prose with no marker: a header, a parameter block, an explanation |
blank(n) |
n newlines | you want vertical space between blocks |
rule(before, after, char) |
a full width rule | you are separating one part of the report from the next |
raw(text) |
the text exactly as given | the text is a tool's output, an exception's message, or the tail of a line |
action(word, msg, run) |
---> Running msg, or ---> Test running msg under --test
|
the verb depends on whether this is a real run or a dry run |
section(title) |
a step, and indents the block under it |
several lines belong under one heading |
pipeline_command(cmd) |
a framed block with one flag per line | you are about to show the external command being run |
trace(text) |
text for the attached comlog | the text belongs in the record of this call, and not in the run's report |
detail records one level deeper than the step it belongs to, which is what
produces its indent. For a run of lines, section does the same for a whole
block, and indent() / dedent() do it by hand. A single line can be nudged
one level with depth=:
log.step("preparing the BOLD runs") # ---> preparing the BOLD runs
log.detail("bold 1: rest") # ... bold 1: rest
with log.section("checking the fieldmaps"): # ---> checking the fieldmaps
log.detail("SE-FM 1 found") # ... SE-FM 1 found
log.warning("SE-FM 2 is missing") # ---> WARNING: SE-FM 2 is missing
log.error("no usable fieldmap", depth=1) # ---> ERROR: no usable fieldmapThe depth of a section is restored when the block ends, including when it ends
because of an exception, so a failure part-way through leaves the rest of the
report at the right level.
A message states the fact; the marker in front of it comes from the method you
called. So an error is written as log.error("no fieldmap"), and the
---> ERROR: in front of it appears because of the method, not because it was
typed.
This matters beyond appearance, because the severity is what makes the line
visible to everything downstream. log.error() increases the log's error count.
That count decides the status of the session, what the run's closing manifest
reports, and the exit status of the qunex process. A line that carries its
severity in the method is counted; a line that describes a failure in its own
words reads as an ordinary step.
The same holds where a helper writes the line for you: the helper takes the severity as an argument.
# the "missing" message is recorded as an error, so it counts as one
status = pc.check_for_file(path, "present", "missing", bad_level="error", _log=log)When a command states its own failure count, that count is used. When it leaves the count open, the log derives it from the errors recorded. And when a command reports no failures while errors were recorded, the log notes the discrepancy in the report, so that the disagreement is visible rather than silently resolved.
raw() writes text through untouched, and there are two kinds of text that
want exactly that:
-
opaque — output produced by something else: a tool's stdout,
raw(str(errormessage))for an exception's text. It must reach the report exactly as it was produced; - continuation — text appended to the line already begun.
The question that decides it: does this line have a severity? If it does, a
level method spells it. If it is verbatim output or the tail of a line, raw()
is the right call.
Blank lines and rules are structure rather than report, and each has a method
that draws it: blank(n) for space, rule() for a full width rule, framed()
for a titled block between two of them.
log.rule() # the rule that opens a session report
log.info(f"Session id: {sinfo['id']}")
...
log.blank()
log.info(f"Bold mask creation completed on {stamp}")
log.rule() # and the one that closes itrule() takes before and after — blank lines above and below, the one thing
that genuinely varies from one call site to the next — and char, which picks
what the rule is drawn with:
log.rule(before=1, after=1) # a blank line either side
log.rule(char=".") # a lighter division, for a block inside the reportThe width does not change with char. A dotted rule and a dashed one are
the same length, so a report divided at two weights still reads as a page. This
is the property the method exists to protect: a rule typed into a string comes
out whatever length the fingers stopped at, and a runlog is read down its left
edge.
A command's preamble — the paragraph at the head of a session report saying what
the command does — is prose, and it belongs in a module level triple-quoted
constant rather than in a string carrying its own \n :
BOLD_STATS_PURPOSE = """\
Per frame statistics are computed for each of the specified BOLD files, from
its movement correction parameter file and an analysis of the image. The
results are saved as *.bstat and *.bscrub files in the images/movement
subfolder."""log.action("Computing", "BOLD image statistics ...", options["run"], level="info")
log.blank()
log.info(BOLD_STATS_PURPOSE)Written this way the paragraph is reviewable in a diff line by line. Where it
has substitutions in it, wrap the result with textwrap.fill rather than laying
the source out around one particular value: an interpolated tail or suffix is
empty as often as not, and a paragraph hand-wrapped around its widest form goes
ragged when the value is short.
The parameters a command quotes back are data, not prose, so they are a list the
report loops over — which also means the list cannot drift from options when a
parameter is renamed:
BOLD_STATS_PARAMETERS = ["mov_radius", "mov_fd", "mov_dvars", "mov_dvarsme"]log.step("Using parameters for computing scrubbing information")
for name in BOLD_STATS_PARAMETERS:
log.detail(f"--{name}: {options[name]}")processing/workflow.py carries four of these preambles, one per command, and
they are the pattern to copy.
Log lines are written with f-strings:
log.error(f"{path} does not exist!")The level methods take the message and the optional depth only, so a format
string with separate arguments is reported as a TypeError where you wrote it.
There is one place in the tree that uses % instead: dicom/dicom2niix.py
interpolates a string containing a backslash, which an f-string slot accepts
only from Python 3.12 onward.
Line length is not constrained — the repository sets no ruff configuration, so
E501 is off, and a long message is better left on one line than folded to look
shorter.
ReportLog is the accumulator described above. Per-BOLD and per-group
executors, study-level commands and utility commands all use it.
SessionLog extends it for a command working on one session: it writes the
session header when it is created, adds the closing footer at finish(), and
carries the session id.
# the header is written here: the session id, the start time, and the pipeline name
log = gl.SessionLog(sinfo, options, "HCP DTI Fit pipeline")log_or_console(_log) returns the log it is given, or — when there is
none — a stand-in that echoes what it records to the console. It is for a
function that is reached both from a command that holds a log and from somewhere
that does not, and it lets the body read the same way in both cases:
def prepare_data(folder, _log=None):
# `log` is the caller's log when there is one, and an echoing stand-in
# otherwise, so every line below is written the same way either way
log = gl.log_or_console(_log)
log.step(f"preparing {folder}")QuNex commands come in two shapes, and the shape decides how the command gets hold of a log.
A processing command is called by general/process.py with the session
information and the options, and it builds its own log:
def my_command(sinfo, options, overwrite=False, thread=0):
# a session log, headed with the session id and this pipeline's name
log = gl.SessionLog(sinfo, options, "My pipeline")A utility command declares a parameter named _log, and
general.core.run_with_log — the runner that stands between gmri and the
command — supplies a ReportLog to any command whose signature declares one:
def my_utility(sourcefolder=None, _log=None):
# `_log` arrives from the runner; log_or_console covers the paths where a
# command is reached directly from python rather than through `qunex`
log = gl.log_or_console(_log)
log.step(f"reading {sourcefolder}")Declaring the parameter is how a command opts in, and it has two useful
properties: the declaration lives in the signature, where a reader of the
function can see it, and the underscore keeps it off the command line, because
the registry builder leaves out signature parameters whose name begins with
_. A registry test holds that in place by asserting that no command's
arguments in qx_commands.yaml start with an underscore.
The plain name log belongs to something else. process.arglist carries
["log", "keep", str], so options["log"] is the comlog retention setting, and
--log is remapped for every command before dispatch. Spelling a log parameter
_log keeps the two apart, and it is the name used throughout the tree.
The name says what the parameter is; the default says whether it is required. A
public helper that can be called without a log declares _log=None. A private
executor that is meaningless without one keeps _log as a required positional
parameter.
Six clauses, all of them small:
-
It returns its log object.
general/process.pywrites the report into the runlog withlog.write_to(run)and readslog.statusfrom it — the(session_id, summary, failed)triple, derived when it is read. -
It states its summary. Either through
finish()orresult(), both of which return the log itself, or by assigninglog.reportandlog.failedand returning the log:return log.finish("My pipeline completed") # summary; the count is derived return log.finish("My pipeline failed", failed=1) # summary and an explicit count
-
It reports a failure by recording it.
log.error(...)counts, and aCommandFailedcaught inside the command is recorded withlog.command_failed(e). -
A command called as a step of another takes the caller's log as
_logand reports into it, so the caller's report holds one continuous story and the caller's error count includes what the step found. -
It collects its external calls in one comlog, with
pc.combined_comlog, and under--testit opens none. -
It honours
--testby reporting what it would do and touching nothing.
When an external call fails, pc.ExternalFailed carries the error message
itself; the context leading up to it is already in the log, so the handler adds
the message and the report reads in order:
except (pc.ExternalFailed, pc.NoSourceFolder) as errormessage:
# the log already holds everything up to the failure; add the error itself
log.raw(str(errormessage))
return log.finish("My pipeline failed", failed=1)A RunContext is created once, before anything is dispatched, and is passed
down through the run — including into parallel worker processes. It holds no
open file handle for that reason: the runlog is opened, appended to under a
lock, and closed again on every write. The lock is what keeps a session's whole
report together in the file when several sessions finish at once.
What it provides:
-
path— the runlog,Log-<command>-<timestamp>.login the run's log folder; -
header()— the provenance line and the call as it would be typed, written before any processing, so that a run interrupted early still says what it was; -
write(text)— an append under the lock; -
comlog(*tags)— opens aComContextfor one call; -
final_report(stati)— the closing manifest; -
write_status(stati)— the status record described below.
When the resolved settings give a run no runlog, path is None and every
write is dropped, so callers can write their reports unconditionally.
The closing report leads with the counts and then groups the calls by how they ended, each entry naming the log that holds its detail:
---> Final report for command hcp_fmri_volume
3 run, 2 successful, 1 failed, 0 did not complete
Successful:
... OP101 ---> HCP fMRI Volume completed [log: .../done_hcp_fmri_volume_OP101_....log]
... OP102 ---> HCP fMRI Volume completed [log: .../done_hcp_fmri_volume_OP102_....log]
Failed:
... OP103 ---> HCP fMRI Volume failed [log: .../error_hcp_fmri_volume_OP103_....log]
---> Not all tasks completed fully!
"Did not complete" is a third outcome alongside success and failure. It covers the calls that reported nothing at all — a worker that was killed, ran out of memory or lost its node — and it makes the run as a whole report a failure, so that a missing answer is treated as a bad one.
A parent process that runs QuNex as a subprocess can ask the run to write down
what it did, by passing --logstatus=<path>. RunContext.write_status then
writes a YAML record: the command, the timestamp, the runlog path, the failure
count, and one {id, summary, failed} entry per session — the same triples the
manifest renders.
run_recipe uses this for every step it runs, which is how a step's outcome
travels back to the recipe as data.
A ComContext owns one comlog:
# the file is created as tmp_…; the subprocess writes straight into it, and on
# leaving the block it is renamed to done_… or error_… by how the block ended
with run.comlog("hcp_fmri_volume", session_id) as comlog:
subprocess.run(call, stdout=comlog.file, stderr=comlog.file)Its properties:
- the name is built from the parts it is given — the command,
--logtagwhen there is one, the session or thread, and the timestamp — joined with underscores and capped at 150 characters, so that a long command and a long session id still produce a name the file system accepts; - the file is created as
tmp_<name>and renamed todone_,error_orincomplete_when it closes, so the state of a run is visible in a directory listing; - it is opened line-buffered, so that
tail -fshows lines as they are written; -
fileis the open handle, ready to pass tosubprocessasstdout=andstderr=;capture_stdout()catches everything printed inside a block;tee(command)runs a command and writes its output to the console and the file at once; - when comlogs are switched off it is the same object with
fileandpathleft atNoneand every write dropped.
A command that runs several external tools collects them in one comlog:
# opens one comlog named for the command and attaches it to the log for the block
with pc.combined_comlog(log, options, "run_freesurfer_full_segmentation",
thread=sinfo["id"]):
# every call inside picks the comlog up from the log it is handed
pc.run_external_for_file(checkfile, command, description, _log=log, ...)The attachment is what does the work: a call made inside the block writes into that file, and everything recorded on the log during the block goes into it as well, so the comlog reads as the whole piece of work rather than as one tool's output. The block also counts the calls that actually ran and reports the count, and it closes the file once — which is also where retention is decided, at one place per command.
Under --test no file is opened, since a dry run makes no external calls.
hcp/qc_hcp.py works differently on purpose: its jobs run in a
ProcessPoolExecutor and cannot share one open file, so its calls keep their
own comlogs.
--log=remove deletes the comlog of a call that finished cleanly. Two rules
apply wherever a comlog would be deleted:
-
a comlog whose contents report errors is kept, and the report says why.
The scan looks for
Error,Error:,ERRORandERROR:. This covers the case the check exists for: a tool that exits with a success status, writes its check file, and reports errors anyway; -
the outcome is recorded whatever happens to the file. A removed comlog
leaves
completed [done], comlog removedin the report, so that the fact of the call and its result survive.
--keep_comlogs protects every comlog of the run ahead of both.
Once a comlog is closed it is copied into each additional folder that
comlog_folders names, and each destination — or a failure to reach one — is
noted in the report.
resolve_logging() produces one frozen LogSettings for the invocation, by
applying six layers in order, each able to override the one before it:
- the built-in defaults;
- the user settings file;
- the study settings file;
- the command's own
logging:field in its.. qx_command:block; -
skip_types, thenskip_commands, thenlog_commands, which wins over both; - the command line:
--logging,--keep_comlogs,--runlog_content.
The result travels down through the drivers as an argument. It is also recorded
in module state by set_active(), and read back by active(). That second path
exists for the helpers at the bottom of processing.core, which are reached
from more than a hundred call sites that pass a folder and hold no context. The
module-level value models what is true of a run — one invocation per process,
resolved once, before any dispatch — and active() returns the defaults when
nothing has set it, so a path that never resolves settings, such as a unit test,
writes logs as if everything were switched on.
run_recipe is the one caller that discovers which study it is working in after
its settings have been resolved, because a recipe file can name a study that the
command line does not. apply_study_settings() layers that study's section over
the resolved settings, with the command line still applied last.
-
bin/qunexdispatches togmri, which works out the study folders and callsresolve_logging(). The result is recorded withset_active(). - The command's type is
processing.*, sogmrihands it togeneral/process.py.process.runmerges the batch file into the options — which can determine the study, and with it the log folder — and then builds theRunContext. -
run.header()writes the provenance line and the call. -
process.runcalls the command once per session, once per subject, or once for the study, with(sinfo, options, overwrite, thread). The command builds aSessionLog, which writes its own header. - The command reports as it works. Around its external calls it opens a combined comlog; the lines it records inside that block go into the comlog as well as the report, and the tools write their output into the same file through its handle.
- The command returns its log. With
--parsessionsgreater than 1 that log travels back from a worker process by being pickled; its console and comlog streams are dropped on the way, since both deliver records as they happen and the records are already in hand. -
process.runcallslog.write_to(run), which appends the report to the runlog and prints it, and readslog.statusfor the session's triple. - Once every session has reported,
run.final_report(stati)writes the manifest andrun.write_status(stati)writes the status record when one was asked for. - When any session reports a failure,
process.runraises, and thequnexprocess ends with a non-zero exit status.
- As above through
resolve_logging().gmribuilds theRunContextitself and callsgeneral.core.run_with_log. -
run_with_logopens a comlog for the call, writes the QuNex banner into it, and prints the path on the console so the call can be followed. - Within
capture_stdout()— which tees to the console for a single call, and redirects into the comlog for one of several running at once — it echoes the call, builds aReportLogthroughlog_or_console(None), and passes it to the command when the command's signature declares_log. - The command reports through that log. The log echoes to
sys.stdout, which for the duration of the call is the comlog, so its lines reach the file as they happen and, for a single call, the terminal as well. - The command returns; its return value is what a python caller of the same function would want — a path, a count, a list of files. The outcome of the call is established from the exception it raised, when it raised one, and from the errors it recorded.
-
run_with_logcloses the report withfinish(), closes the comlog asdone_orerror_, and writes the call's entry into the runlog: the call's name (or, for a per-session call, its own echo), the report whenrunlog_contentisfullor when the call has no comlog, and a status line naming the comlog. - It returns a
CallOutcome(name, failed, error, comlog)togmri, which raises when the call failed, so the process ends with a non-zero exit status.
Run over sessions, the same path runs inside a ProcessPoolExecutor: one comlog
per session, one shared runlog, and the manifest at the end. The per-session
output goes to each session's own comlog, and the terminal carries the
announcements, the completion lines and the manifest — which keeps it legible
when several sessions are writing at once.
run_recipe runs each of its steps as a child qunex process. It gives each
step a --logstatus path and reads the record back, so what it reports about a
step is what that step recorded about itself. When a step leaves no record — its
process was killed — the step is reported from its exit status. Under
layout: nested each step logs into its own numbered subfolder of the recipe's
log folder.
The two examples below use every method of the report vocabulary once. They are written for the paper rather than lifted from the tree, so that one command can show the whole set.
import qx_utilities.general.log as gl
import qx_utilities.processing.core as pc
def demo_command(sinfo, options, overwrite=False, thread=0):
# the session log writes its header as it is created
log = gl.SessionLog(sinfo, options, "Demo pipeline")
log.info("Demonstrating the report vocabulary.") # prose, no marker
log.blank() # one blank line
log.step("checking the session's data") # the step being started
log.detail(f"session folder: {sinfo['hcp']}") # a particular of that step
# the helper records "T1w image present" or, as an error, "T1w image missing"
status = pc.check_for_file(
f"{sinfo['hcp']}/T1w/T1w_acpc_dc.nii.gz",
"T1w image present",
"T1w image missing",
bad_level="error", # the missing-file message is recorded as an error
_log=log, # the log to record it in
)
# everything inside the block is recorded one level deeper
with log.section("preparing the BOLD runs"):
log.detail("bold 1: rest")
log.warning("bold 2 has no matching fieldmap, using the session default")
if not status:
log.error("cannot continue without a T1w image") # counts as a failure
return log.finish("Demo pipeline failed", failed=1)
command = "wb_command -volume-math ... --fix-nan 0"
log.pipeline_command(command) # the call, framed, one flag per line
# one comlog for the whole command, named after it
with pc.combined_comlog(log, options, "demo_command", thread=sinfo["id"]):
# "Running the demo pipeline", or "Test running …" under --test
log.action("Running", "the demo pipeline", options["run"])
try:
pc.run_external_for_file(
f"{sinfo['hcp']}/demo/done.txt", # the file that proves it ran
command, # the command to run
"running the demo pipeline", # how it is described in the report
overwrite=overwrite,
thread=sinfo["id"],
task="demo",
logfolder=options["comlogs"],
_log=log,
)
except pc.ExternalFailed as errormessage:
log.raw(str(errormessage)) # the tool's error, verbatim
return log.finish("Demo pipeline failed", failed=1)
# the summary; the failure count is derived from the errors recorded
return log.finish("Demo pipeline completed")The report that reaches the runlog reads as follows. The lines
run_external_for_file records for its own call are left out here, and the
paths and timestamps are illustrative:
------------------------------------------------------------
Session id: OP101
[started on Tuesday, 11. August 2026 14:03:22]
Running Demo pipeline [HCPStyleData] ...
Demonstrating the report vocabulary.
---> checking the session's data
... session folder: /studies/demo/sessions/OP101/hcp
... T1w image present
---> preparing the BOLD runs
... bold 1: rest
---> WARNING: bold 2 has no matching fieldmap, using the session default
------------------------------------------------------------
Running HCP Pipelines command via QuNex:
wb_command -volume-math ...
--fix-nan 0
------------------------------------------------------------
---> Running the demo pipeline
---> ran 1 external command
---> logfile: /studies/demo/logs/2026-08-11_14.03.22.417063_demo_command/comlogs/done_demo_command_OP101_....log
followed by the footer finish() adds:
Demo pipeline completed on Tuesday, 11. August 2026 14:07:55
------------------------------------------------------------
Every marker, indent and newline in that report came from the method that was called. The failure count came from the errors recorded.
The vocabulary is the same. The differences are that the log arrives rather than
being built, and that the return value serves a python caller.
pipeline_command and action appear here for completeness — they earn their
place in a utility command when it, too, runs an external tool or has a dry-run
mode.
import subprocess
import qx_utilities.general.log as gl
def demo_utility(sourcefolder=None, targetfolder=None, run="run", _log=None):
"""
``demo_utility [--sourcefolder=<path>] [--targetfolder=<path>]``
.. qx_command:
type: utility
"""
# the runner's log, or an echoing stand-in when called directly from python
log = gl.log_or_console(_log)
log.info("Demo utility command.") # prose, no marker
log.blank() # one blank line
log.step("reading the source folder") # the step being started
log.detail(f"source: {sourcefolder}") # a particular of that step
copied = []
with log.section("copying the packages"): # heading; the block nests under it
for package in ["packet01", "packet02"]:
if package == "packet02":
log.error(f"{package} could not be read") # counts as a failure
continue
log.detail(f"{package} copied")
copied.append(package)
log.warning(f"{len(copied)} of 2 packages copied") # the run carries on
command = f"dcm2niix -o {targetfolder} {sourcefolder}"
log.pipeline_command(command, title="Running the conversion via QuNex:")
log.action("Running", "the conversion", run) # "Test running …" when run="test"
result = subprocess.run(command, shell=True, capture_output=True, text=True)
log.raw("\n" + result.stdout) # the tool's output, verbatim
log.step(f"finished in {targetfolder}")
return copied # for a python callerThe command recorded an error, so the call is reported as failed and the process ends with a non-zero exit status. The report is in the call's comlog, alongside anything the command or its subprocesses printed. The runlog carries the entry:
demo_utility
ERROR running demo_utility [log: .../comlogs/error_demo_utility_....log]
The runlog's header has already spelled out the call, so a single call is
entered by name; a per-session call is entered with its own echo, since its
arguments differ from the run's. Under --runlog_content=full the report itself
goes between those two lines.
A run collects its logs in a folder of its own, under the study's logs folder:
<study>
├── logs
│ ├── 2026-08-11_09.12.44.881204_import_dicom
│ │ ├── Log-import_dicom-2026-08-11_09.12.44.881204.log <- the runlog
│ │ └── comlogs
│ │ ├── done_import_dicom_OP101_2026-08-11_09.12.45.310887.log
│ │ └── done_import_dicom_OP102_2026-08-11_09.13.02.774190.log
│ ├── 2026-08-11_10.02.10.104512_hcp_fmri_volume
│ │ ├── Log-hcp_fmri_volume-2026-08-11_10.02.10.104512.log
│ │ ├── batchlogs <- scheduler jobs
│ │ │ └── SLURM_hcp_fmri_volume_job1240.2026-08-11_10.02.11.207446.log
│ │ └── comlogs
│ │ ├── done_hcp_fmri_volume_OP101_2026-08-11_10.02.30.118324.log
│ │ └── error_hcp_fmri_volume_OP103_2026-08-11_10.44.51.663018.log
│ └── 2026-08-11_11.30.00.000715_run_recipe_hcp
│ ├── Log-run_recipe_hcp-2026-08-11_11.30.00.000715.log
│ └── comlogs
├── processing
│ ├── batch.txt
│ └── scripts
└── sessions
├── OP101
│ ├── hcp
│ │ └── OP101
│ │ └── logs
│ │ └── comlogs <- with --comlog_folders="study|hcp"
│ └── logs
│ └── comlogs <- with --comlog_folders="study|session"
└── inbox
Three settings change that picture:
-
layout: legacycollects the logs of every run in<study>/processing/logs; -
layout: nestedadds a numbered subfolder for each step of arun_reciperun; -
outside_studydecides where a run with no study writes:~/qunex_logs, the working directory, or a path.
A comlog is written into the first folder that comlog_folders names and copied
into the others, so one file can sit both with the study's logs and inside the
session it belongs to.
QuNex reads a user settings file from the home folder — accepted at
~/.qunex_settings.yaml, ~/qunex_settings.yaml,
~/qunex/qunex_settings.yaml or ~/.qunex/qunex_settings.yaml, and a file
found in more than one of those is reported as an error naming all of them — and
a study file at <study>/qunex_settings.yaml, whose keys are layered over the
user's.
logging:
enabled: true
runlog: true
comlog: true
outside_study: home
layout: default
keep_comlogs: false
comlog_folders: [study]
runlog_content: manifest
skip_commands: []
log_commands: []
skip_types: []| Key | Values | What it does |
|---|---|---|
enabled |
true | false
|
the master switch for all logging |
runlog |
true | false
|
write the per-run summary log |
comlog |
true | false
|
write the per-call raw output logs. With comlogs off, an external tool's output goes to the console |
outside_study |
home | cwd | <path>
|
where a run with no study logs. home is ~/qunex_logs
|
layout |
default | legacy | nested
|
<study>/logs/<stamp>_<command>; <study>/processing/logs; or default plus a folder per recipe step |
keep_comlogs |
true | false
|
protects every comlog from removal |
comlog_folders |
study, session, hcp, <path> — one or more |
where each comlog goes: the first is where it is written, the rest are where it is copied |
runlog_content |
manifest | full
|
whether a utility command's report is placed in the runlog as well as in its comlog |
skip_commands |
list of names | commands to run without logging |
log_commands |
list of names | commands to always log; wins over both skip lists |
skip_types |
list of registry types | skip by command type, e.g. [utility]
|
| Parameter | Values | What it does |
|---|---|---|
--logging |
none | comlog | runlog | full
|
sets enabled, runlog and comlog together, over both settings files and the command's own declaration |
--logfolder |
<path> | legacy
|
places this run's logs at a path, or selects the legacy layout |
--logtag |
a string | an extra part in comlog names |
--log |
keep | remove
|
whether a comlog that finished cleanly is deleted |
--comlog_folders |
study, session, hcp, <path>, comma or | separated |
where comlogs go, over the settings value |
--keep_comlogs |
bare, or yes|no
|
protects every comlog of this run |
--runlog_content |
manifest | full
|
as the setting |
--logstatus |
<path> |
writes the run's outcome as a YAML record for a parent process |
--log also accepts the destination values study, session and hcp: they
are read as --comlog_folders and a warning names the values that were moved.
runlog_content is subject to one rule that is not settable: a call with no
comlog places its report in the runlog whatever the setting says, since
manifest asks to avoid holding the same text twice rather than to let go of
the only copy.
A command can declare its own logging in its .. qx_command: block, which the
registry carries into qx_commands.yaml:
.. qx_command:
type: utility
logging: comlog # none | comlog | runlog | bothThe settings files are applied first, this declaration next, and the command line last.
Read from the outside in, the machinery above adds up to a handful of things a user can rely on:
-
one
qunexcall leaves one runlog, holding every session's report and a manifest at the end; -
the report reads the same everywhere, because the markers and indents come
from the renderer:
--->is a step,...a detail,---> ERROR:a failure that has been counted; - a failure reaches the exit status. A failing session, a utility command that recorded an error, and a worker that never reported all end the process with a non-zero status, so shell scripts, CI and schedulers can act on it;
-
every log file says how it ended in its own name —
tmp_while it runs, thendone_,error_orincomplete_; -
a running call can be followed with
tail -fon the path QuNex prints as the call starts, which is also the live view when several sessions are running at once; -
logging is a policy, not a habit. A study's
qunex_settings.yamlsets it once for everyone working in that study, and a command line adjusts it for one run.
-
A
print()is a notice for the console; a record is what survives. A print is right where the fact is already recorded durably and the console needs it at a moment, or in a form, that the report cannot serve — the runlog does not stream, so a line recorded at the start of a two-hour run reaches the console when the run ends. Where only the first holds, record it; where only the second does, record it and echo it.python/tests/test_print_baseline.pykeeps a budget of prints per module and names the exemptions. - Say what a line is, and let the log spell it.
-
Reach for
error()when something failed, since that is the line the count, the manifest and the exit status can see. -
A helper takes
_logand appends to it, which keeps one command's story in one report. - The parameter is
_log.