Skip to content

[Bug Report] Modify after a partial fill rests less than requested (stale filledQuantity carried into the reprice); also an unconditional O(book-depth) tax on every message #688

Description

@OPTIONPOOL

Found while integrating opexdev/core's matching-engine-core module into an open matching-engine benchmark, the Matching Engine Performance Challenge — it cross-checks engines against the byte-identical consensus of other open-source engines. Cross-checking SimpleOrderBook's output against that consensus turned up a modify-handling bug: a modify that follows a partial fill on the same order rests less quantity than requested. Separately, while tracing that bug I noticed handleNewOrderCommand/handleCancelCommand/handleEditCommand all pay an unconditional, book-depth-proportional cost on every message they accept, regardless of message type — both are traced to source below, with a minimal fix for each.

Pinned at current main (acccd9b462067998ee5c257a5cdcc056233c08cc).

Environment

  • Commit: acccd9b462067998ee5c257a5cdcc056233c08cc
  • Module: matching-engine/matching-engine-core — a self-contained sub-module (own pom.xml); its own Kotlin source imports only exchange.core2:collections (the LongAdaptiveRadixTreeMap price-level map) and slf4j-api, so it compiles and runs standalone against just those two jars plus the Kotlin stdlib, no Spring/Kafka/Redis/coroutines needed
  • Kotlin 1.9.24 (kotlinc) targeting the module's declared Kotlin 1.6/Java 11 bytecode; run on OpenJDK 21, aarch64
  • Driven directly through the module's own public API: engine.SimpleOrderBook.handleNewOrderCommand / handleCancelCommand / handleEditCommand

1. A modify following a partial fill rests less than requested

What happens

SimpleOrderBook.handleEditCommand (SimpleOrderBook.kt:218-346) implements a modify as its own cancel-then-reinsert: it removes the old resting SimpleOrder and builds a new one at the requested price/quantity. The rebuilt order, however, carries the old order's filledQuantity forward unchanged:

val newOrder = SimpleOrder(
    order.id,
    orderCommand.ouid,
    orderCommand.uuid,
    orderCommand.price,
    orderCommand.quantity,      // the NEW requested quantity
    order.matchConstraint,
    order.orderType,
    order.direction,
    order.filledQuantity,       // <- the OLD order's already-filled amount, carried forward
    null,
    null,
    null
)

(SimpleOrderBook.kt:244-257)

SimpleOrder.remainedQuantity() is quantity - filledQuantity (SimpleOrder.kt:18), so once newOrder is matched/re-queued, what actually rests is orderCommand.quantity - order.filledQuantity, not orderCommand.quantity. This engine's modify is already a fresh cancel+reinsert — the old order is removed with the same handleCancelOrder a real cancel uses, and the rebuilt order is re-matched like a new arrival — so carrying the pre-modify fill history into that fresh quantity means any modify following a partial fill on the same order (a routine "reprice while already partially filled" or "raise the quantity after a partial fill") rests less than requested, silently. Nothing validates quantity >= filledQuantity, either — an edit below the filled amount rests a bucket with negative totalQuantity; I verified -2 rests.

Minimal reproduction

Public API only (SimpleOrderBook, OrderCreateCommand, OrderEditCommand, the model enums), on a fresh book:

// Repro.kt — build from the module's compiled classes:
//   kotlinc -cp collections-0.5.1.jar:slf4j-api-2.0.16.jar:<matching-engine-core classes> Repro.kt -include-runtime -d repro.jar
//   java -cp repro.jar:collections-0.5.1.jar:slf4j-api-2.0.16.jar:<matching-engine-core classes> ReproKt
import co.nilin.opex.matching.engine.core.engine.SimpleOrderBook
import co.nilin.opex.matching.engine.core.inout.OrderCreateCommand
import co.nilin.opex.matching.engine.core.inout.OrderEditCommand
import co.nilin.opex.matching.engine.core.model.*

fun main() {
    val pair = Pair("BASE", "QUOTE")
    val book = SimpleOrderBook(pair, false)

    // order 1: rest 10 SELL @ 100
    val o1 = book.handleNewOrderCommand(
        OrderCreateCommand("1", "1", pair, 100, 10, OrderDirection.ASK, MatchConstraint.GTC, OrderType.LIMIT_ORDER))!!
    // order 2: BUY 4 @ 100 -> partially fills order 1 (6 left resting)
    book.handleNewOrderCommand(
        OrderCreateCommand("2", "2", pair, 100, 4, OrderDirection.BID, MatchConstraint.GTC, OrderType.LIMIT_ORDER))
    // MODIFY order 1 -> SELL 6 @ 101 -- its exact remaining size, just repriced
    book.handleEditCommand(OrderEditCommand("1", "1", o1.id()!!, pair, 101, 6))
    // order 3: IOC BUY 6 @ 101 should fully consume the resting 6 in one trade, zero residual
    val o3 = book.handleNewOrderCommand(
        OrderCreateCommand("3", "3", pair, 101, 6, OrderDirection.BID, MatchConstraint.IOC, OrderType.LIMIT_ORDER))!!

    println("order 3 filled: ${o3.persistent().filledQuantity} / 6")
    println("resting ask qty still at 101: ${book.askOrders[101]?.totalQuantity ?: 0}")
}
SLF4J(W): No SLF4J providers were found.
SLF4J(W): Defaulting to no-operation (NOP) logger implementation
SLF4J(W): See https://www.slf4j.org/codes.html#noProviders for further details.
order 3 filled: 2 / 6
resting ask qty still at 101: 0

(The three SLF4J(W) lines are just the standard slf4j-api warning that no logging backend is on the classpath — harmless, and expected since the module logs through LoggerFactory.getLogger but nothing here supplies an implementation.)

Order 1 rests 10 SELL@100, is partially filled 4 by order 2 (6 left resting), then MODIFY(1, SELL, 6, 101) re-prices it to 101 at exactly its own remaining size (6) — a pure reprice, not a size change. The IOC buy for 6 at 101 should fully fill in one trade with zero residual; instead it only fills 2, because the modify actually rested 6 - 4(the stale filledQuantity) = 2, not 6. (The resting ask qty line reads 0 afterward because the IOC consumed the 2 that actually rested — not because the modify rested the requested amount — printing it before the IOC order confirms only 2 is there.)

Suggested fix

A modify's rebuilt order should start unfilled, exactly like a real cancel+reinsert would produce:

             order.direction,
-            order.filledQuantity,
+            0,
             null,
             null,
             null
         )

I compiled this into a scratch copy and confirmed the fix: the repro now prints order 3 filled: 6 / 6 and resting ask qty still at 101: 0 (fully consumed, as expected) — verified by recompiling and rerunning against the patched classes, not just reading the source. The module's own SimpleOrderBookUnitTest.kt (all 17 @Test methods, run through junit-platform-launcher; the one dead kotlinx.coroutines.Dispatchers.Default statement, and its now-unresolvable import kotlinx.coroutines.Dispatchers line, needed dropping to compile standalone — see the smaller notes at the bottom) still reports 17/17 successful, identical to the as-shipped run: none of its existing cases modify an order that has already been partially filled, so the fix doesn't touch anything they commit to.

2. Every accepted message pays an unconditional O(current book depth) tax, regardless of type

What happens

handleNewOrderCommand and handleCancelCommand both end, on every call that gets past their early reject-returns, by computing a full snapshot of the book and publishing it, and by logging a state dump that materializes both sides of the book just to read their sizes:

EventDispatcher.emit(OrderBookPublishedEvent(persistent()))
logCurrentState()

(SimpleOrderBook.kt:159-160, end of handleNewOrderCommand; the same pair appears at :214-215 ending handleCancelCommand; inside handleEditCommand the persistent() emit alone (no logCurrentState()) appears once per branch, at :277/:320)

persistent() (SimpleOrderBook.kt:555-561) deep-copies every currently-resting order into a fresh PersistentOrderBook unconditionally — orders.values.map { order -> order.persistent() } — with no check whether anything is listening for the event it's about to be wrapped in. logCurrentState() (:601-615) unconditionally builds askOrders.entriesList() and bidOrders.entriesList() (each a full materialization of the ART price-level map into a List) purely to read .size in a log string — again with no check whether the configured logger will even use the string it's about to build. In this integration neither the event nor the log backend has any listener/backend attached (and per a full-module grep, no test in the module registers a listener for the event either), so both computations are pure, provably-discarded overhead — yet they still run in full on every message.

Separately (same class, not touched by the fix below): handleCancelCommand finds the order to cancel with a linear scan, orders.entries.find { it.value.ouid == orderCommand.ouid } (:174), rather than the direct keyed lookup that handleEditCommand already uses one function over (orders.remove(orderCommand.orderId), :219) and that the module's own SimpleOrderBookUnitTest.kt already always populates (every OrderCancelCommand its tests construct passes the real internal id as orderId, e.g. OrderCancelCommand(firstOrderId, uuid, firstOrder!!.id()!!, pair)). I did not touch this half, since trusting orderId for a cancel is a slightly bigger behavioral question than the guard-only fix below (whatever populates OrderCancelRequestEvent.orderId one layer up, in matching-engine-app, would need confirming first) — flagging it here since it's the other half of the same "cost scales with book depth, not message count" shape.

Between the always-on persistent()/log-state pair and the linear-scan cancel, every accepted message this engine processes costs at least O(current book depth) — independent of whether that message crosses, rests, or cancels anything. Cross-checking this engine's output against the reference baseline on identical (scenario, seed) 100k-order (≈200k-message) runs shows the shape directly: the static scenario, which leaves the deepest resting book of the five, ran at roughly a third the throughput of the other four (which cross more and so carry a shallower average resting depth) on the same adapter, same message count.

Suggested fix (the always-on persist/log half only)

Skip the two provably-discarded computations when nothing consumes them — add one small helper to EventDispatcher (purely additive) and guard the four call sites plus the log body:

--- a/matching-engine-core/src/main/kotlin/co/nilin/opex/matching/engine/core/eventh/EventDispatcher.kt
+++ b/matching-engine-core/src/main/kotlin/co/nilin/opex/matching/engine/core/eventh/EventDispatcher.kt
@@
+    @JvmStatic
+    fun hasListeners(type: Class<*>): Boolean = eventsHandler[type]?.isNotEmpty() ?: false
+
     fun emit(event: CoreEvent) {
--- a/matching-engine-core/src/main/kotlin/co/nilin/opex/matching/engine/core/engine/SimpleOrderBook.kt
+++ b/matching-engine-core/src/main/kotlin/co/nilin/opex/matching/engine/core/engine/SimpleOrderBook.kt
@@ (four call sites: end of handleNewOrderCommand, end of handleCancelCommand,
@@  and once in each branch of handleEditCommand)
-        EventDispatcher.emit(OrderBookPublishedEvent(persistent()))
+        if (EventDispatcher.hasListeners(OrderBookPublishedEvent::class.java)) {
+            EventDispatcher.emit(OrderBookPublishedEvent(persistent()))
+        }
@@
     private fun logCurrentState() {
+        if (!logger.isInfoEnabled) return
         logger.info(

This changes nothing observable whenever something does listen for OrderBookPublishedEvent or does run with an INFO-level SLF4J backend attached — both paths still run exactly as before. It only skips the work when, as here, nothing will ever read the result.

I compiled this into a scratch copy: the module's own test suite (same 17/17) still passes unchanged, and a stress test of exactly this shape — 5,000 same-price orders rested one at a time then swept by a single IOC (the worst case pre-patch: depth grows by one per insert, so the deep-copy-plus-materialize pair above is paid at ever-increasing depth every time) — still produces byte-identical output to independent reference engines after the patch.

Smaller notes

A few smaller things noticed alongside the above, not filed as separate issues:

  • handleCancelCommand's own linear ouid scan (SimpleOrderBook.kt:174) is the other O(depth) contributor described in Finding 2 above; a real fix needs confirming what matching-engine-app's OrderCancelRequestEvent.orderId is populated with before trusting it as a map key — outside what I could verify from this module alone.
  • logNewOrder/handleCancelCommand's own opening logger.info(...) calls build fixed-size strings (no book materialization) and aren't part of the O(depth) cost above; left untouched.
  • SimpleOrderBookUnitTest.kt:41 (givenEmptyOrderBook_whenGtcBidLimitOrderCreated_then1BucketWithSize1) has a bare Dispatchers.Default statement — a kotlinx.coroutines reference whose value is never used or asserted on anything, in a module whose own .kt sources (confirmed by grep) never otherwise touch coroutines. Looks like dead code (an unused import's companion reference, maybe copy-pasted) rather than anything intentional; harmless either way, noted since it's the one place kotlinx.coroutines appears in this module's source.

This is just a time-stamped snapshot of one commit, offered in case it's useful — not a comment on the project, which reads cleanly otherwise as a real, self-contained price-time matcher. Thanks for sharing the engine; happy to send either repro above as a small test if that helps.

Respectfully submitted.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions