Global @mismatch {} handler not called?

[ralphlange]

For a complex binary protocol I needed an index counter that increments after each message to the device. Implemented as a calcRecord with a matching command in the protocol that steps it.

incr {
    exec "dbpf "$R_Index".PROC 1";
}

The command is being called from the protocols as:

SuperComplexBinaryMessage {
    out 0xAA 0x00 0x07 $4 $4 0x00 0x00 "%("$R_Index")r" 0x42 $5 $crc;
    in  0xAA 0x00 0x09 0x00 0x00 $4 0x00 "%("$R_Index")=r" 0x42 "%("$R_StatusRBK")r" $5 0x00 $crc;
    incr;
}

Global handlers exist:

@mismatch { incr; }
@readTimeout { incr; }
@replyTimeout { incr; }

While debugging, I found the global handler not being called at a format mismatch.

2021/07/23 09:03:26.566608 SCI0303 VV-VVOI-SCHR-DISP:MDR1511-ASTRT: mismatch after 2 bytes "<aa><00>"
2021/07/23 09:03:26.566616 SCI0303 VV-VVOI-SCHR-DISP:MDR1511-ASTRT: got "<09><00><00><01><00><05>E<07><00><00>..." where "<0f>" was expected
2021/07/23 09:03:26.566624 SCI0303 StreamCore.cc:1133: StreamCore::readCallback(VV-VVOI-SCHR-DISP:MDR1511-ASTRT) match failure
2021/07/23 09:03:26.566634 SCI0303 StreamCore.cc:447: StreamCore::finishProtocol(VV-VVOI-SCHR-DISP:MDR1511-ASTRT, ScanError) bus owner
2021/07/23 09:03:26.566643 SCI0303 StreamCore.cc:514: starting exception handler
2021/07/23 09:03:26.566654 SCI0303 StreamCore.cc:544: StreamCore::evalCommand(VV-VVOI-SCHR-DISP:MDR1511-ASTRT): activeCommand = end
2021/07/23 09:03:26.566664 SCI0303 StreamCore.cc:447: StreamCore::finishProtocol(VV-VVOI-SCHR-DISP:MDR1511-ASTRT, Success) bus owner
2021/07/23 09:03:26.566674 SCI0303 AsynDriverInterface.cc:609: AsynDriverInterface::unlock(VV-VVOI-SCHR-DISP:MDR1511-ASTRT)
2021/07/23 09:03:26.566685 SCI0303 AsynDriverInterface.cc:1473: AsynDriverInterface::finish(VV-VVOI-SCHR-DISP:MDR1511-ASTRT) start
2021/07/23 09:03:26.566692 SCI0303 AsynDriverInterface.cc:1483: AsynDriverInterface::finish(VV-VVOI-SCHR-DISP:MDR1511-ASTRT) done
2021/07/23 09:03:26.566698 SCI0303 StreamEpics.cc:969: Stream::protocolFinishHook(VV-VVOI-SCHR-DISP:MDR1511-ASTRT, ScanError)
2021/07/23 09:03:26.566715 cbLow-0 StreamEpics.cc:1047: recordProcessCallback(VV-VVOI-SCHR-DISP:MDR1511-ASTRT) processing record
2021/07/23 09:03:26.566731 cbLow-0 StreamEpics.cc:843: Stream::process(VV-VVOI-SCHR-DISP:MDR1511-ASTRT)
2021/07/23 09:03:26.566738 cbLow-0 StreamEpics.cc:849: Stream::process(VV-VVOI-SCHR-DISP:MDR1511-ASTRT) error status=CALC (12)

StreamDevice 2.8.10
EPICS Asyn 4.37
EPICS Base 7.0.3.1
RHEL 7.4