Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 4 additions & 0 deletions di/log/init.q
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
// simple stdout logger - default log dependency for di.* modules
\l ::log.q

export:([trace;debug;info;warn;error;fatal;createLog])
169 changes: 169 additions & 0 deletions di/log/log.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,169 @@
# Log

`log.q` is the default logging implementation for `di.*` modules. It writes formatted lines to stdout and satisfies the log dependency contract expected by modules such as `di.email`.

## Usage

```q
logger:use`di.log
logger.trace[`mymodule;"entering function"]
logger.debug[`mymodule;"value is 42"]
logger.info[`mymodule;"starting up"]
logger.warn[`mymodule;"disk usage above 80%"]
logger.error[`mymodule;"connection failed"]
logger.fatal[`mymodule;"unrecoverable error, shutting down"]
```

Output format:

```
2026-04-09T12:00:00.000000000 [TRACE] [mymodule] entering function
2026-04-09T12:00:00.001000000 [DEBUG] [mymodule] value is 42
2026-04-09T12:00:00.002000000 [INFO] [mymodule] starting up
2026-04-09T12:00:00.003000000 [WARN] [mymodule] disk usage above 80%
2026-04-09T12:00:00.004000000 [ERROR] [mymodule] connection failed
2026-04-09T12:00:00.005000000 [FATAL] [mymodule] unrecoverable error, shutting down
```

## Injecting into other modules

All `di.*` modules that accept a log dependency expect a dictionary with keys `` `info`warn`error ``, each a function with signature `{[ctx;msg]}`.

```q
logger:use`di.log
logdep:`info`warn`error!(logger.info;logger.warn;logger.error)

email:use`di.email
email.init[enlist[`log]!enlist logdep]
```

You can extend the injected dictionary with `trace`, `debug`, and `fatal` for modules that support them:

```q
logdep:`trace`debug`info`warn`error`fatal!(logger.trace;logger.debug;logger.info;logger.warn;logger.error;logger.fatal)
```

`di.log` has no dependencies of its own, so there's no `init` to call on it first — use
`defaultdict` to skip building the dict by hand. It's the dependency already wrapped
as `` `log!enlist logdict ``, ready to pass straight into any `di.*` module's `init`:

```q
mylog:use`di.log
email:use`di.email
email.init[mylog.defaultdict]
```

## createLog

`createLog` is a factory that returns an independent logger instance with level filtering, multiple output sinks, and configurable format templates. Each call to `createLog` produces a separate instance with its own state.

```q
logger:use`di.log
mylog:logger.createLog[]

mylog.setlvl `warn / suppress trace, debug, info
mylog.info "this is suppressed" / returns () silently
mylog.warn "this appears"

mylog.setfmt `syslog / switch to syslog format
mylog.addfmt[`compact;"$l $m"] / add a custom format
mylog.setfmt `compact

mylog.add[2i;`error`fatal] / add stderr sink for error and fatal
mylog.remove[1i;`trace] / remove stdout from trace level
```

### Sinks

A sink is a handle (integer file descriptor or function) passed to `add`. If a function is provided it is called with the formatted line string. Built-in handles follow standard q conventions: `1i` is stdout, `2i` is stderr.

```q
buf:();
capture:{[msg] buf,:enlist msg}; / function sink - captures output
mylog.add[capture;`info`warn`error]
mylog.info "captured"
buf / ("2026-...captured\n")
mylog.remove[capture;`info]
```

### Format templates

Three built-in formats are available:

| Name | Template | Example output |
|---|---|---|
| `basic` (default) | `$p $l PID[$i] HOST[$h] $m` | `2026-04-09T12:00:00.000000000 INFO PID[1234] HOST[myhost] message` |
| `syslog` | `<$s> $m` | `<6> message` |
| `raw` | `$m` | `message` |

Template variables: `$p` timestamp, `$l` level, `$i` PID, `$h` hostname, `$m` message, `$s` syslog severity number.

## API

### `trace`
Parameters: `[ctx; msg]`

Write a trace-level message to stdout.

- `ctx` — symbol context tag (e.g. `` `mymodule ``)
- `msg` — string message

### `debug`
Parameters: `[ctx; msg]`

Write a debug-level message to stdout.

### `info`
Parameters: `[ctx; msg]`

Write an info-level message to stdout.

### `warn`
Parameters: `[ctx; msg]`

Write a warning-level message to stdout.

### `error`
Parameters: `[ctx; msg]`

Write an error-level message to stdout.

### `fatal`
Parameters: `[ctx; msg]`

Write a fatal-level message to stdout.

### `defaultdict`
A dictionary, not a function.

`` `log!enlist(`info`warn`error!(info;warn;error))`` — the log dependency dict pre-wrapped
exactly as any `di.*` module's `init` expects `deps`, so it can be passed straight through
without building it by hand.

### `createLog`
Parameters: none

Returns an independent logger instance as a dictionary of functions. Each call returns a new instance with isolated state.

Returned keys: `` `trace`debug`info`warn`error`fatal`add`remove`setfmt`getfmt`addfmt`setlvl`getlvl ``

| Function | Parameters | Description |
|---|---|---|
| `trace`..`fatal` | `[msg]` | Write a message at the given level (filtered by active level) |
| `setlvl` | `[lvl]` | Set minimum level; one of `` `trace`debug`info`warn`error`fatal `` |
| `getlvl` | `[_]` | Return current minimum level |
| `setfmt` | `[name]` | Switch to a named format template |
| `getfmt` | `[_]` | Return current format name |
| `addfmt` | `[name;template]` | Register a new named format template |
| `add` | `[handle;lvls]` | Add a sink for one or more levels; returns the handle |
| `remove` | `[handle;lvl]` | Remove a sink from a level |

## Log dependency contract

The log dependency contract used across `di.*` modules requires a dictionary:

```q
`info`warn`error!({[ctx;msg] ...};{[ctx;msg] ...};{[ctx;msg] ...})
```

`di.log` satisfies this contract. You can also supply any custom implementation with the same signatures.
190 changes: 190 additions & 0 deletions di/log/log.q
Original file line number Diff line number Diff line change
@@ -0,0 +1,190 @@
/ simple stdout logger for di.* modules
/ provides info, warn, error, trace, debug, fatal with signature {[ctx;msg]}
/ ctx is a symbol context tag, msg is a string
/ also provides createLog, a factory for rich structured logger instances

/ os-aware newline
nl:$[.z.o in `w32`w64;"\r\n";"\n"];

/ log levels in priority order
lvls:`trace`debug`info`warn`error`fatal;

/ syslog severity per level (rfc5424)
syslogLvl:lvls!7 7 6 4 3 2i;

/ built-in format templates for createLog instances
fmts:`basic`syslog`raw!("$p $l PID[$i] HOST[$h] $m";"<$s> $m";"$m");

/ format pattern handlers for createLog instances; each takes {[level;msg]}
/ level is an uppercase string (e.g. "INFO"), msg is the formatted message string
pattern:"plihms~"!(
{[x;y] string .z.p};
{[x;y] x};
{[x;y] string .z.i};
{[x;y] string .z.h};
{[x;y] y};
{[x;y] string .z.M.syslogLvl`$lower x};
{[x;y] "$"});

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

.z.M.syslogLvl references the module namespace dictionary's syslogLvl key, but syslogLvl is a plain name defined at the top level of the file (line 12). At the time the pattern dict is evaluated, .z.M may not yet be set (it is typically assigned by the module loader after the file is loaded), so this lookup will fail with a rank/type error or silently return null. Access the file-level name directly as syslogLvl instead of .z.M.syslogLvl.


/ split a format template on delimiter, returning (textparts; substitutionfunctions)
/ escaped delimiter (e.g. $$) is replaced by $~ which resolves to literal $
fmtprep:{[del;rep;fmt]
fmt:ssr[fmt;del,del;del,"~"];
parts:del vs fmt;
fns:rep@first each 1_parts;
(enlist[first parts],1_/:1_parts;fns)
};

/ apply a prepared format returning the assembled line string
/ level is an uppercase string, msg is the formatted message string
fmtapply:{[prep;level;msg]
textparts:prep 0;
fns:prep 1;
vals:fns .\:(level;msg);
raze first[textparts],vals,'1_textparts
};

/ apply printf-style variable substitution to a message
/ msg is a plain string or (fmtstring;arg1;arg2;...)
/ %s converts to string, %r uses .Q.s1, %% becomes a literal percent
fmtmsg:{[msg]
$[10h=abs type msg;
msg;
[fmt:first msg;
args:1_msg;
fmt:ssr[fmt;"%%";"\000"];
parts:"%" vs fmt;
subs:"sr"!({$[10h=abs type x;x;-11h=type x;string x;'`type]};.Q.s1);
result:first[parts],raze {[subs;args;parts;i]
part:parts[1+i];
code:first part;
rest:1_part;
if[not code in key subs;'`$"unsupported format char: ",enlist code];

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

fmtmsg signals `type for a list message whose first element is not a 10h/string argument type (e.g. a symbol format string like (`fmt;arg) where fmt is a symbol), but only after partially processing. More critically, the args indexing args[i] will silently return null when i is out of range (more %s/%r specifiers in the format string than supplied arguments), producing malformed log lines with no error. There is no guard that count args matches the number of format specifiers.

(subs[code] args[i]),rest
}[subs;args;parts;] each til count[parts]-1;
ssr[result;"\000";"%"]
]
]};

/ format and write a log line to stdout using the dependency-contract format
logline:{[level;ctx;msg]
-1 (string .z.p)," [",level,"] [",string[ctx],"] ",msg;
};


/ instance counter and per-instance state; bare names fall back to .z.M when .z.m not yet set
i:0;
inst:()!();

/ factory helper: returns a 1-arg {[msg]} log function for the given level and instance
/ each entry in sink is a (handle;sender) pair; sender is called with the formatted text
makelevel:{[id;gv;lvl]
{[id;gv;lvl;msg]
if[(lvls?lvl)<lvls?gv`lvl;:()];
txt:fmtapply[gv`prep;upper string lvl;fmtmsg msg],nl;
{[txt;pair]

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The error handler in makelevel swallows all write errors silently: @[last pair;txt;{x}] catches any signal and returns the error string unnoticed. A failed write to a closed handle or a function sink that signals will be silently discarded with no indication of failure. Use a handler that at minimum writes to stderr, e.g. {-2 "log sink error: ",x}.

@[last pair;txt;{x}]
}[txt;] each (gv`sink)[lvl];
}[id;gv;lvl;]
};

/ update field k with value v in instance id's state

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

updInst writes back via .z.m.inst:state, but in add (line 112) the same assignment is done inline as .z.m.inst:state — bypassing updInst. This is inconsistent but not itself a bug. The real issue is that neither path is protected against concurrent modification: if two log instances call add/remove or setlvl concurrently (e.g. from a timer and a message handler in the same process), the read-modify-write on .z.m.inst is a race condition. This is a structural issue with the shared mutable dictionary design.

updInst:{[id;k;v]
state:inst;
state[id;k]:v;
.z.m.inst:state;
};


/ ============================================================
/ public api
/ ============================================================

/ simple dependency-contract-compatible log functions; each has signature {[ctx;msg]}
trace:{[ctx;msg] logline["TRACE";ctx;msg];};
debug:{[ctx;msg] logline["DEBUG";ctx;msg];};
info:{[ctx;msg] logline["INFO";ctx;msg];};
warn:{[ctx;msg] logline["WARN";ctx;msg];};
error:{[ctx;msg] logline["ERROR";ctx;msg];};
fatal:{[ctx;msg] logline["FATAL";ctx;msg];};

/ pre-wrapped log dependency dict ready to pass straight into any di.* module's init
/ e.g. email.init[mylog.defaultdict]

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

add accepts either a bare handle or a 2-element (handle;fn) pair, but the remove function (line 151) only matches on first p (the handle component). If the user registers the same handle twice with different sender functions, remove will remove both entries for that handle rather than just the one for the specified sender. The intent of storing (handle;sender) pairs is to allow the same handle with different senders, but remove conflates them. The fix is to match on the full pair: not h~p when h is a pair, or keep the existing handle-only match only when h is a scalar.

defaultdict:(enlist`log)!enlist(`info`warn`error!(info;warn;error));

/ create a logger instance with level filtering, multiple formatters and sinks
/ returns a dictionary of functions; each call returns an independent instance
/ sink entries are (handle;sender) pairs; sender is called with the formatted text
createLog:{[]
/ increment instance counter and capture id
.z.m.i+:1;
id:i;
/ initialise state for this instance; no separate handler dict needed
snk:lvls!(count lvls)#enlist();
prp:fmtprep["$";pattern;fmts`basic];
state:inst;
state[id]:`sink`lvl`fmtname`fmts`prep!(snk;`info;`basic;fmts;prp);
.z.m.inst:state;

/ helpers that close over id to read and write this instance's state
gv:{.z.m.inst[x][y]}[id;];
wv:updInst[id;;];

/ set active format by name; recomputes the prepared format template
setfmt:{[gv;wv;name]
f:gv`fmts;
if[not name in key f;'"invalid format: ",string name];
wv[`prep;fmtprep["$";pattern;f name]];
wv[`fmtname;name];
}[gv;wv;];

/ get the current format name; 1-arg (dummy ignored) so gv executes in module context
getfmt:{[gv;x] gv`fmtname}[gv;];

/ add a custom named format template string
addfmt:{[gv;wv;name;fmt]
wv[`fmts;@[gv`fmts;name;:;fmt]];
}[gv;wv;;];

/ set minimum log level; messages below this level are suppressed
setlvl:{[gv;wv;newlvl]
if[not newlvl in lvls;'"invalid level: ",string newlvl];
wv[`lvl;newlvl];
}[gv;wv;];

/ get the current minimum log level; 1-arg (dummy ignored) so gv executes in module context
getlvl:{[gv;x] gv`lvl}[gv;];

/ add a sink (handle or (handle;fn) pair) for one or more log levels
/ each sink entry is stored as (handle;sender) so mixed types never collide in a dict
add:{[id;gv;h;sinklvls]
handle:$[0h=type h;first h;h];
sender:$[0h=type h;last h;h];
{[id;handle;sender;lvl]
state:.z.m.inst;
sink:state[id;`sink];
sink[lvl],:enlist(handle;sender);
state[id;`sink]:sink;
.z.m.inst:state;
}[id;handle;sender;] each (),sinklvls;
handle
}[id;gv;;];

/ remove a handle from a log level's sink list
remove:{[id;h;lvl]
state:.z.m.inst;
sink:state[id;`sink];
sink[lvl]:sink[lvl] where {[h;p] not h~first p}[h;] each sink[lvl];
state[id;`sink]:sink;
.z.m.inst:state;
h
}[id;;];

/ initialise default sink: stdout for all levels
add[1i;lvls];

/ return public interface as a dictionary of functions
(lvls,`add`remove`setfmt`getfmt`addfmt`setlvl`getlvl)!
(makelevel[id;gv;] each lvls),
(add;remove;setfmt;getfmt;addfmt;setlvl;getlvl)
};
Loading