Skip to main content
Profile pictureTaxisDB

Logger - Data Access API User Guide

UserAPI•Version 0.8.1•

Setting the log level with Setup

Every process that logs should call Setup^logger once, before any LOG*^logger calls, to configure the active severity threshold, console output, and stack tracing for that process:

D Setup^logger("DEBUG",1,0)

Parameters:

ParamMeaningDefault
levelstrMinimum severity to record — see levels below"ERROR"
output1 = also WRITE each line to console, 0 = silent1
trace1 = capture a $STACK trace with every log entry, 0 = don’t0

Anything below the configured level is filtered out and never written to ^TXLOG. For example, D Setup^logger("WARNING",1,0) will record WARNING, ERROR, and CRITICAL messages, but silently drop DEBUG and INFO ones.

You can call Setup again at any point to change the level mid-process (e.g. drop into "DEBUG" while chasing a bug, then back to "INFO" once you’re done). Each call opens a new session rather than overwriting the old configuration — see Sessions inside ^TXLOG below.

Shortcut commands

For convenience, common Setup calls are pre-registered as keyboard/menu shortcuts in ^TBKW, so you don’t have to type the full DO command each time:

S ^TBKW("DO Setup^logger(""DEBUG"",1,0)",0)="DEBUG"          ; X DEBUG
S ^TBKW("DO Setup^logger(""INFO"",1,0)",0)="INFO"            ; X INFO
S ^TBKW("DO Setup^logger(""WARNING"",1,0)",0)="WARNING"      ; X WARNING
S ^TBKW("DO Setup^logger(""ERROR"",1,0)",0)="ERROR"          ; X ERROR
S ^TBKW("DO Setup^logger(""CRITICAL"",1,0)",0)="CRITICAL"    ; X CRITICAL

Each entry maps a label (DEBUG, INFO, WARNING, ERROR, CRITICAL) to the full Setup^logger call it represents. Invoking the shortcut (X DEBUG, X INFO, etc.) runs DO Setup^logger(...) for you, so switching the active log level becomes a single keystroke command instead of having to remember and retype the Setup^logger syntax.

Severity levels

logger.m uses the same five-level scheme as most logging frameworks, from least to most severe:

Level stringNumeric valueMeaning
DEBUG10Detailed diagnostic information, normally suppressed in production
INFO20Normal operational confirmations (the default)
WARNING30Unexpected situation, but execution continues
ERROR40An operation failed
CRITICAL50Severe failure — the system may not continue

Setting a level with Setup records that level and everything more severe. So "WARNING" logs WARNING/ERROR/CRITICAL; "DEBUG" logs everything.

Level strings are case-insensitive, and any unrecognized string falls back to INFO (the same default LOG itself falls back to if it’s ever invoked without a configured level at all).

Once configured, use the matching wrapper to actually write a message, supplying the calling module’s name ("API", "SAPI", etc.) and the message text:

D LOGDEBUG("API","GetEID: resolved via aid=1008 val=tt0011100")
D LOGINFO("SAPI","Transact: committed 4 records, tx=7407")
D LOGWARNING("API","Cache miss, falling back to disk lookup")
D LOGERROR("API","Assert: %ERecords not initialised")
D LOGCRITICAL("SAPI","Transact: unrecoverable global lock failure")

You never need to call the lower-level LOG(level,name,msg) entry point directly — the five wrappers above exist precisely so callers don’t need to know or hard-code the numeric values (10/20/30/40/50).

Sessions inside ^TXLOG

Log entries and configuration are stored in the ^TXLOG global, keyed first by $JOB (the process ID), then by a session number.

A new session is opened every time Setup/INIT runs — either because you explicitly called Setup^logger again to change the level, or because LOG^logger auto-initializes one the first time it’s called in a process that never ran Setup at all. This means one process can accumulate several sessions over its lifetime, each with its own configuration and its own block of log lines, while sequence numbers (SEQ) keep counting upward across all of them rather than resetting.

^TXLOG($JOB,"SESSIONS")         -> how many sessions this process has opened
^TXLOG($JOB,"CURRENT")          -> which session number is active right now

^TXLOG($JOB,session,"CFG","LEVEL")             -> numeric level (10/20/30/40/50)
^TXLOG($JOB,session,"CFG","OUTPUT")            -> 1/0, console echo
^TXLOG($JOB,session,"CFG","TRACE")             -> 1/0, stack trace capture
^TXLOG($JOB,session,"CFG","SEQ")               -> running count of log entries
^TXLOG($JOB,session,"CFG","STARTED at")        -> timestamp, session 1 via Setup
^TXLOG($JOB,session,"CFG","RESTARTED at")      -> timestamp, session >1 via Setup
^TXLOG($JOB,session,"CFG","AUTO-STARTED at")   -> timestamp, opened by the LOG guard

^TXLOG($JOB,session,seq)                        -> one formatted log line
^TXLOG($JOB,session,seq,i)                      -> optional $STACK trace frame i

Each log line is stored as a single formatted string:

<timestamp> | <name> | <LEVEL> | <message>

Worked example

The dump below shows two processes ($JOB = 87796 and 111999), with three sessions between them.

Process 87796, session 1 — never had Setup called explicitly, so LOG’s guard auto-initialized it ("AUTO-STARTED at") with the safe defaults LEVEL=20 (INFO), OUTPUT=1, TRACE=0. 31 entries were written before the process moved on:

^TXLOG(87796,1,28)="2026-07-09T20:08:18.709977 | SAPI | INFO | Transact: committed 4 records, tx=7407"
^TXLOG(87796,1,29)="2026-07-09T20:08:18.711141 | API | INFO | AssertRecord: staged — Total Records: 1"
^TXLOG(87796,1,30)="2026-07-09T20:08:18.711161 | API | INFO | Assert: staged 1 record(s) for ns=sandbox isBulkLoad=0 — ready for Transact"
^TXLOG(87796,1,31)="2026-07-09T20:08:18.716295 | API | INFO | Transact: committed 1 records, tx=7408"
^TXLOG(87796,1,"CFG","AUTO-STARTED at")="2026-07-09T20:08:18.629929"
^TXLOG(87796,1,"CFG","LEVEL")=20
^TXLOG(87796,1,"CFG","OUTPUT")=1
^TXLOG(87796,1,"CFG","SEQ")=31
^TXLOG(87796,1,"CFG","TRACE")=0

Process 87796, session 2 — at some point the same process called D Setup^logger("DEBUG",1,0) (e.g. via the X DEBUG shortcut), which opened a second session, labelled "RESTARTED at" since it wasn’t the first session for this job. Note SEQ continues from 87, not from 0 — it picks up where session 1’s SEQ (31) left off plus everything logged in between, staying unique for the whole process:

^TXLOG(87796,2,82)="2026-07-10T18:50:30.616771 | API | DEBUG | GetEID: resolved via aid=1008 val=tt0011100"
^TXLOG(87796,2,83)="2026-07-10T18:50:30.616829 | SAPI | DEBUG | IsNewRangeValue: not new — aid=1005, val=Seven @en, IsRefValType=0, IsRangeValue=1"
^TXLOG(87796,2,84)="2026-07-10T18:50:30.616861 | SAPI | DEBUG | ResolveAV: (RES)-EXISTS ^TBDR(1005,Seven @en) → K3ED.01882E"
^TXLOG(87796,2,85)="2026-07-10T18:50:30.616901 | SAPI | DEBUG | IsNewRangeValue: not new — aid=1005, val=Se7en @en, IsRefValType=0, IsRangeValue=1"
^TXLOG(87796,2,86)="2026-07-10T18:50:30.616923 | SAPI | DEBUG | ResolveAV: (RES)-EXISTS ^TBDR(1005,Se7en @en) → K3ED.018845"
^TXLOG(87796,2,87)="2026-07-10T18:50:30.616944 | API | DEBUG | GetEID: resolved via EID: 656332f6450df1p9ft7q"
^TXLOG(87796,2,"CFG","LEVEL")=10
^TXLOG(87796,2,"CFG","OUTPUT")=1
^TXLOG(87796,2,"CFG","RESTARTED at")="2026-07-10T18:37:21.521999"
^TXLOG(87796,2,"CFG","SEQ")=87
^TXLOG(87796,2,"CFG","TRACE")=0

^TXLOG(87796,"CURRENT")=2 and ^TXLOG(87796,"SESSIONS")=2 confirm this process has opened two sessions total, and session 2 is the one LOG currently writes into.

Process 111999, session 1 — a separate process (different $JOB), again never called Setup explicitly, so it got its own "AUTO-STARTED at" session at the default INFO level. This one happened to hit several ERROR-level lines right at startup (%ERecords not initialised) before settling into normal INFO traffic:

^TXLOG(111999,1,1)="2026-07-10T19:26:08.258952 | API | ERROR | Assert: %ERecords not initialised"
^TXLOG(111999,1,2)="2026-07-10T19:26:08.258996 | API | ERROR | Transact: %ERecords not initialised — call INIT^api first"
^TXLOG(111999,1,3)="2026-07-10T19:26:08.259027 | API | ERROR | Transact: invalid staging data — no transaction level, skipping rollback"
^TXLOG(111999,1,4)="2026-07-10T19:26:47.727568 | API | INFO | AssertRecord: staged — Total Records: 1"
...
^TXLOG(111999,1,15)="2026-07-10T19:26:47.755534 | API | INFO | Transact: committed 1 records, tx=7413"
^TXLOG(111999,1,"CFG","AUTO-STARTED at")="2026-07-10T19:26:08.258747"
^TXLOG(111999,1,"CFG","LEVEL")=20
^TXLOG(111999,1,"CFG","OUTPUT")=1
^TXLOG(111999,1,"CFG","SEQ")=15
^TXLOG(111999,1,"CFG","TRACE")=0
^TXLOG(111999,"CURRENT")=1
^TXLOG(111999,"SESSIONS")=1

This process never re-ran Setup, so it only ever has one session ("SESSIONS")=1), and "CURRENT")=1 still points at it.

Takeaways from the example

  • Two processes, three sessions total — sessions are scoped per $JOB, not shared globally, so 87796 and 111999 never interfere with each other even though both use ^TXLOG.
  • AUTO-STARTED vs RESTARTED/STARTED tells you why a session exists: whether a caller explicitly ran Setup, or whether LOG had to bail the process out with safe defaults because nobody did.
  • SEQ never resets within a process — it’s the mechanism that keeps every log line’s number unique and increasing across re-inits, so you can always tell ordering even after a Setup call switches sessions.
  • Only the active session’s CFG matters for filtering — LOG always reads ^TXLOG($JOB,"CURRENT") to find which session’s LEVEL/OUTPUT/ TRACE govern the current call.