MUMPS developer on retainer: ORDMGR LOCK +^ORDFILL clobbered when VALIDATE^AUDLOG issues non-incremental LOCK ^AUDREC — two concurrent processes pass validation without holding fill lock

InterSystems IRIS 2022.1 • MUMPS/M • LOCK incremental vs. non-incremental • ^ORDFILL ^AUDREC • Lock Manager • retainer billing

At Riverside Medical Center, a pharmacy order management system running on InterSystems IRIS 2022.1 began generating duplicate fill events for medication orders. The pattern was intermittent — three or four times per month, two nurses would submit fill requests for the same medication order at nearly the same second, and both would succeed. Both created a dispensing record. The patient received two dispensings. The pharmacy team flagged it as a concurrency issue: something in the ordering workflow was not properly serializing concurrent fill attempts. The MUMPS retainer developer was called to investigate.

The order management system was written in MUMPS. The global ^ORDFILL stored fill records indexed by order number. The routine ORDMGR.m handled fill processing. When a nurse submitted a fill request, ORDMGR acquired an incremental LOCK on the order fill global, validated the order, updated the fill status, and released the lock. The code looked correct. But the duplicate fills kept happening.

The ORDMGR routine and the LOCK acquisition

ORDMGR’s fill processing section acquired the lock and called the audit validation subroutine:

FILLORD(ordno)
    ; Acquire exclusive lock on the order fill record
    LOCK +^ORDFILL(ordno):10
    IF '$TEST DO TIMEOUT QUIT
    ;
    ; Check: is this order already filled?
    IF $DATA(^ORDFILL(ordno,"FILLED")) DO ALRFILL QUIT
    ;
    ; Validate the order against audit log rules
    DO VALIDATE^AUDLOG(ordno)
    ;
    ; Write the fill record
    SET ^ORDFILL(ordno,"FILLED")=1
    SET ^ORDFILL(ordno,"FILLTM")=$HOROLOG
    SET ^ORDFILL(ordno,"NURSE")=$USERNAME
    ;
    LOCK -^ORDFILL(ordno)
    QUIT

The logic looked sound. LOCK +^ORDFILL(ordno):10 acquires an incremental exclusive lock on ^ORDFILL(ordno), with a 10-second timeout. The + prefix is critical: it means this lock is added to the current process’s lock set without releasing any currently held locks. After validation, the fill is written, and LOCK -^ORDFILL(ordno) releases just this one lock. This is the correct MUMPS incremental lock pattern.

The developer opened AUDLOG.m and looked at the VALIDATE tag.

The subroutine LOCK that clobbered the caller

The audit log validation routine, written by a different developer two years earlier, looked like this:

VALIDATE(ordno)    ; Validate order against audit log — called from ORDMGR
    ; Acquire lock on the audit record for this order
    LOCK ^AUDREC(ordno):5        ; ← non-incremental LOCK — no + prefix
    IF '$TEST DO AUDTIMO QUIT
    ;
    ; Check audit flags
    SET flags=$GET(^AUDREC(ordno,"FLAGS"))
    IF flags["HOLD" DO AUDHLD QUIT
    IF flags["CANCEL" DO AUDCNL QUIT
    ;
    ; Write validation timestamp
    SET ^AUDREC(ordno,"VALDTM")=$HOROLOG
    ;
    LOCK -^AUDREC(ordno)
    QUIT

The bug is on the first LOCK line: LOCK ^AUDREC(ordno):5. There is no + prefix. In MUMPS, a LOCK command without the + prefix is a non-incremental lock — it releases all currently held locks for the process, then acquires the specified lock. This is not an error in the AUDLOG routine in isolation; it works correctly when called from code that holds no prior locks. But ORDMGR called it while holding LOCK +^ORDFILL(ordno).

The sequence of events during the duplicate fill incident:

09:14:32.000  PID 4271 (Nurse A)  LOCK +^ORDFILL(847)  — acquired
09:14:32.003  PID 4271            DO VALIDATE^AUDLOG(847)
09:14:32.004  PID 4271            AUDLOG: LOCK ^AUDREC(847)
              ↑ non-incremental LOCK releases ^ORDFILL(847) first,
                then acquires ^AUDREC(847)
09:14:32.005  PID 4312 (Nurse B)  LOCK +^ORDFILL(847)  — ACQUIRED
              ↑ ^ORDFILL(847) is now available — PID 4271 released it
09:14:32.006  PID 4312            $DATA(^ORDFILL(847,"FILLED")) = 0  — not filled yet
09:14:32.007  PID 4312            DO VALIDATE^AUDLOG(847)
09:14:32.041  PID 4271            AUDLOG: LOCK -^AUDREC(847) — released
09:14:32.042  PID 4271 (back in ORDMGR) — proceeds as if ^ORDFILL(847) held
09:14:32.043  PID 4271            SET ^ORDFILL(847,"FILLED")=1
09:14:32.048  PID 4312            SET ^ORDFILL(847,"FILLED")=1
              ↑ both writes succeed — last writer wins
09:14:32.049  Two fill events written for order 847

The IRIS Lock Manager confirmed this. At the moment PID 4271 returned from VALIDATE^AUDLOG, the Lock Manager showed ^ORDFILL(847) as not in PID 4271’s lock set — it had been released by the non-incremental LOCK in AUDLOG and was currently held by PID 4312.

Diagnosing with the IRIS Lock Manager

To reproduce and confirm the bug during testing, the developer used two tools. First, the InterSystems IRIS Management Portal: System Operation → Locks shows all currently held locks by process, global name, and lock count. During a controlled test run of ORDMGR, the developer added a HANG 2 (2-second pause) inside VALIDATE^AUDLOG after the LOCK ^AUDREC line, and checked the Lock Manager in another window. The Lock Manager showed only ^AUDREC(TEST01) in the lock set for the test process — ^ORDFILL(TEST01) was absent, confirming that the non-incremental LOCK had released it.

Second, the $ZUTIL(67,9) function in Caché/IRIS (on older implementations) or the programmatic lock inspection through LOCK ^ORDFILL:0 with a zero timeout (a non-blocking try-lock that succeeds if the lock is not held) confirmed that after VALIDATE^AUDLOG returned, a competing process could acquire ^ORDFILL(ordno) without waiting.

The root cause was unambiguous: the two routines were written by different developers at different times. ORDMGR’s author used incremental locks correctly; AUDLOG’s author was unaware that VALIDATE would be called while another lock was already held. In MUMPS, the distinction between LOCK ^X and LOCK +^X is a single character, and there is no language-level warning when a non-incremental LOCK silently releases a lock that the caller depends on.

Fix: incremental LOCK in VALIDATE^AUDLOG

The fix was a one-character change in AUDLOG.m: add + to the LOCK command on the VALIDATE tag, and ensure the corresponding decremental unlock is present before all QUIT paths:

VALIDATE(ordno)    ; Validate order against audit log
    ; Acquire lock on the audit record — incremental, preserves caller's locks
    LOCK +^AUDREC(ordno):5       ; ← + added
    IF '$TEST DO AUDTIMO LOCK -^AUDREC(ordno) QUIT
    ;
    SET flags=$GET(^AUDREC(ordno,"FLAGS"))
    IF flags["HOLD" DO AUDHLD LOCK -^AUDREC(ordno) QUIT
    IF flags["CANCEL" DO AUDCNL LOCK -^AUDREC(ordno) QUIT
    ;
    SET ^AUDREC(ordno,"VALDTM")=$HOROLOG
    ;
    LOCK -^AUDREC(ordno)         ; ← decremental release
    QUIT

The LOCK -^AUDREC(ordno) lines were also added before each early QUIT path (AUDTIMO, AUDHLD, AUDCNL) that previously had no unlock before returning. After the fix, the IRIS Lock Manager showed both ^ORDFILL(ordno) and ^AUDREC(ordno) in PID 4271’s lock set simultaneously while VALIDATE ran — the fill lock was never released by the audit validation call. PID 4312’s LOCK +^ORDFILL(847) blocked as intended until PID 4271 completed the fill and issued LOCK -^ORDFILL(847).

After deployment: duplicate fill events dropped from three per month to zero. The audit was extended to all routines in the AUDLOG namespace that used non-incremental LOCK, and two additional VALIDATE-type entry points were found and corrected.

The retainer developer also added a code review note to the AUDLOG module: when writing a routine that may be called from within a caller’s lock scope, use incremental LOCK (+) exclusively. Non-incremental LOCK is only safe when a routine is invoked at the top level with no ambient lock context.

How HourTab helps MUMPS retainer developers

The LOCK clobber investigation took 3.5 hours. The fix itself — adding a single + character — took five minutes. The retainer log needed to capture the 3.5 hours of investigation: Lock Manager trace setup, HANG-pause test harness, call-tree LOCK audit across three routines (ORDMGR, AUDLOG/VALIDATE, AUDLOG/NOTIFY), and the regression run confirming both ^ORDFILL and ^AUDREC held simultaneously. A flat invoice showing “3.5h MUMPS debugging” invites pushback from a pharmacy IT director who sees a one-character code change and wonders why diagnosis took so long. A HourTab entry that names the global, both lock calls, the Lock Manager trace, and the before/after fill-event count is self-justifying.

HourTab turns a time-tracker CSV into a public retainer-hours URL your client can bookmark — no login, no portal, no “how many hours do I have left?” emails. Free for one retainer. $9/mo for up to ten.

FAQ: MUMPS developer retainers

See also: MUMPS language developer retainer (naked references, $ORDER) · InterSystems Caché developer retainer · Natural language developer retainer