Fiddling with Clojure transactions

In this blog, I will share my experience with Clojure Transactions, focusing on how Clojure’s Software Transactional Memory (STM) model performs under load. I'll examine this through the example of a Snowflake ID generator, which is crucial for generating unique IDs in distributed systems. Recently, at my workplace, we faced latency issues in one of our high-throughput services, and the Snowflake ID implementation using Clojure transactions was identified as the bottleneck.

What is Snowflake ID?

In short, a Snowflake ID is a 64-bit long strictly increasing Integer. It’s useful for generating IDs in a distributed manner.

When your system needs a new ID, the algorithm goes like this:

1. Captures the current timestamp (milliseconds since epoch)

2. Combining it with the pre-assigned server ID

3. Adds a sequence number that resets each millisecond

4. If multiple IDs are requested in the same millisecond, the sequence number increments

5. If the sequence number exceeds its maximum value, the algorithm waits for the next millisecond

This simple approach creates IDs that are guaranteed to be unique across your distributed system, assuming each server has a unique server ID and clocks don't move backwards. Since the ID generator relies on coordinated updates to last-timestamp and sequence-number, using STM seemed ideal for ensuring atomicity and isolation.

---

Here is a brief explanation of Clojure's transaction-related functions used in the later implementations:

dosync - Runs the expressions (in an implicit do) within a transaction that includes these expressions and any nested calls. It starts a transaction if one is not already running on this thread. Any uncaught exception will abort the transaction and exit dosync. The expressions may run more than once, but any effects on Refs will be atomic. ensure - Returns the in-transaction value of a ref and protects the ref from being changed by other transactions. ref-set - Sets the value of a ref within a transaction.

🔧 The Initial STM-based Implementation

(defonce bit-lengths {:timestamp 36 :instance 8 :sequence-number 8})
(defonce bit-positions
  {:timestamp (+ (:instance bit-lengths) (:sequence-number bit-lengths))
   :instance (:sequence-number bit-lengths)
   :sequence-number 0})

(defonce max-sequence-number
  (dec (bit-shift-left 1 (:sequence-number bit-lengths))))
(defonce max-instance-number
  (dec (bit-shift-left 1 (:instance bit-lengths))))
(defonce max-timestamp
  (dec (bit-shift-left 1 (:timestamp bit-lengths))))

(defonce epoch 1704067200000) ;; 2024-01-01T00:00:00

(defonce instance-id (delay (rand-int max-instance-number)))
(defonce instance-chunk (delay (bit-shift-left (deref instance-id) (:instance bit-positions))))

(def sequence-number (ref 0))
(def last-timestamp (ref 0))


(defn- create-id [timestamp sequence-number]
  (let [time-id (- timestamp epoch)
        time-chunk (bit-shift-left time-id (:timestamp bit-positions))]
    (bit-or time-chunk @instance-chunk sequence-number)))


(defn- generate-id [now-fn]
  (dosync
   (let [current-timestamp (now-fn)]

     (when (< current-timestamp (ensure last-timestamp))
       (throw (ex-info (format "Clock moved backwards, rejecting requests for %dms"
                               (- (ensure last-timestamp) current-timestamp))
                       {:current-ts current-timestamp
                        :last-ts (ensure last-timestamp)})))

     (if (= current-timestamp (ensure last-timestamp))
       (if (> (ensure sequence-number) max-sequence-number)
         (do ;; reset sequence number and wait for next millisecond
           (ref-set sequence-number 1)
           (let [final-timestamp
                 (loop []
                   (let [fresh-timestamp (now-fn)]
                     (if (> fresh-timestamp current-timestamp)
                       fresh-timestamp
                       (recur))))]
             (ref-set last-timestamp final-timestamp))
           (create-id (ensure last-timestamp) 0))

         ;; Increment sequence number, then generate new ID
         (let [sequence-value (ensure sequence-number)]
           (alter sequence-number inc)
           (create-id current-timestamp sequence-value)))

       (do
         (ref-set sequence-number 1)
         (ref-set last-timestamp current-timestamp)
         (create-id current-timestamp 0))))))


(defn get-snowflake-id
  []
  (generate-id (fn [] (System/currentTimeMillis))))

In the above implementation, we are using Refs to store sequence-number and last-timestamp. And we are updating these two vars in a Clojure transaction using the dosync. Using transactions makes sense as we want to perform atomic updates on sequence-number and last-timestamp.

The implementation looks good.

📊 Benchmarking Serial vs Parallel

Let’s test it -

> (get-snowflake-id)
2654257038396672

It works! Now, let’s stress test it.

We will generate 10000 IDs in serial -

> (def ids (time (mapv (fn [_] (get-snowflake-id)) (range 10000))))
"Elapsed time: 89.929958 msecs"

We will generate 10000 IDs in parallel with 100 threads -

> (require '[com.climate.claypoole :as cp]) 
> (defonce cp-threadpool (cp/threadpool 100 :daemon false :name "stress-threadpool"))

> (def ids (time (doall (cp/pmap cp-threadpool (fn [_] (get-snowflake-id)) (range 10000)))))
"Elapsed time: 71579.44925 msecs"

Something weird happened with the parallel ID generation. It took over 71 seconds, while serial generation took 89 milliseconds.

🚨 The Bottleneck: Ref Contention

I instrumented different parts of the code with the following time-on-threshold macro to understand what's going on. If the time elapsed is more than the set threshold of 100 ms, it logs the time.

(defmacro time-on-threshold
  "Evaluates expr and prints the time it took.  Returns the value of
 expr."
  {:added "1.0"}
  [expr-name expr]
  `(let [start# (. System (nanoTime))
         ret# ~expr
         time-taken-ms# (/ (double (- (. System (nanoTime)) start#)) 1000000.0)]
     (when (> time-taken-ms# 100)
       (prn (str "Expr - " expr-name ". Elapsed time: " time-taken-ms#  " msecs")))
     ret#))

After instrumenting all suspects like ref-set and alter, I reran the parallel ID generation.

I found out that it’s the ref-set that is taking a long time to execute. Sometimes it takes even more than 400 ms as well.

To better understand the issue, I needed to explore Clojure’s implementation of transactions.

Clojure transactions use snapshot isolation with multiversion concurrency control.

What is Snapshot Isolation?

Snapshot isolation is a database concurrency control method where each transaction operates on a consistent snapshot of the data as it existed at the start of the transaction. It enhances performance by reducing locking and blocking, allowing multiple transactions to access and modify data concurrently.

Although Snapshot Isolation promotes concurrency but in our case, we are seeing throughput reduction with increased concurrency.

🔍 Internals of LockingTransaction

Clojure implements transactions using a Java class called LockingTransaction, which is located in clojure.lang package.

It took me a while to understand the basic flow of the LockingTransaction class.

Here is the outline of the class -

Transaction Management

• runInTransaction(Callable fn): Main entry point for running code in a transaction

• run(Callable fn): Core transaction execution logic with retry mechanism

• abort(): Explicitly abort a transaction

• isRunning(): Check if a transaction is currently running

• getRunning(): Get the current running transaction

Ref Operations

• doGet(Ref ref): Get value from a ref within a transaction

• doSet(Ref ref, Object val): Set value to a ref within a transaction

• doEnsure(Ref ref): Ensure a ref hasn't changed since the transaction start

• doCommute(Ref ref, IFn fn, ISeq args): Apply a commutative function to a ref

On investigating the above functions, I noticed that a transaction can be retried 10k times in the run method of LockingTransaction class due to conflict from other ongoing transactions.

This was interesting. I wanted to know how often a transaction is being retried to generate 10000 Snowflake IDs in parallel.

I added a log on each retry to understand the retry count for each transaction.

Object run(Callable fn) throws Exception {
    for (int i = 0; !done && i < RETRY_LIMIT; i++) {
        try {
            // do the ref operations
            // throw RetryEx in case of conflict and lock acquisition failure
        }

        catch (RetryEx retry) {
            System.out.println("Retry " + i + " / " + RETRY_LIMIT);
        }
    }
}

I built the Clojure Java artifact locally and deployed it in my Clojure application.

Not to my surprise, some of the transactions were retrying more than 100 times.

Retry 108 / 10000
Retry 107 / 10000
Retry 114 / 10000
Retry 41 / 10000
Retry 91 / 10000
Retry 107 / 10000
Retry 112 / 10000

🤔 What if we don’t use transactions?

Using transactions to perform atomic updates on refs is resource-intensive. What if we don't use transactions at all? Let's revisit the original goals. We want to give exclusive access to refs to one thread at a time to avoid repeating generated IDs. We can achieve this with synchronization in the generate-id function. We'll use the locking function to lock the ID generation logic.

Let’s try it -

(defonce bit-lengths {:timestamp 36 :instance 8 :sequence-number 8})
(defonce bit-positions
  {:timestamp (+ (:instance bit-lengths) (:sequence-number bit-lengths))
   :instance (:sequence-number bit-lengths)
   :sequence-number 0})

(defonce max-sequence-number
  (dec (bit-shift-left 1 (:sequence-number bit-lengths))))
(defonce max-instance-number
  (dec (bit-shift-left 1 (:instance bit-lengths))))
(defonce max-timestamp
  (dec (bit-shift-left 1 (:timestamp bit-lengths))))

(defonce epoch 1704067200000) ;; 2024-01-01T00:00:00

(defonce instance-id (delay (rand-int max-instance-number)))
(defonce instance-chunk (delay (bit-shift-left (deref instance-id) (:instance bit-positions))))

(def sequence-number (atom 0))
(def last-timestamp (atom 0))


(defn- create-id [timestamp sequence-number]
  (let [time-id (- timestamp epoch)
        time-chunk (bit-shift-left time-id (:timestamp bit-positions))]
    (bit-or time-chunk @instance-chunk sequence-number)))


(def lock (Object.))


(defn- generate-id [now-fn]
  (locking lock
    (let [current-timestamp (now-fn)]
      (when (< current-timestamp @last-timestamp)
        (throw (ex-info (format "Clock moved backwards, rejecting requests for %dms"
                                (- @last-timestamp current-timestamp))
                        {:current-ts current-timestamp
                         :last-ts @last-timestamp})))

      (if (= current-timestamp @last-timestamp)
        (if (> @sequence-number max-sequence-number)
          (do ;; reset sequence number and wait for next millisecond
            (reset! sequence-number 1)
            (let [final-timestamp
                  (loop []
                    (let [fresh-timestamp (now-fn)]
                      (if (> fresh-timestamp current-timestamp)
                        fresh-timestamp
                        (recur))))]
              (reset! last-timestamp final-timestamp))
            (create-id @last-timestamp 0))

          ;; Increment sequence number, then generate new ID
          (let [sequence-value @sequence-number]
            (swap! sequence-number inc)
            (create-id current-timestamp sequence-value)))

        (do
          (reset! sequence-number 1)
          (reset! last-timestamp current-timestamp)
          (create-id current-timestamp 0))))))


(defn get-snowflake-id
  []
  (generate-id (fn [] (System/currentTimeMillis))))

Above, you can see that we have replaced refs with atoms and transactions with a simple lock similar to Java’s synchronisation block.

Now let’s stress test it again.

Generate 10000 IDs in serial -

(def ids (time (mapv (fn [_] (get-snowflake-id)) (range 10000))))
"Elapsed time: 48.121375 msecs"

Generate 10000 IDs in parallel -

(def ids (time (doall (cp/pmap cp-threadpool (fn [_](get-snowflake-id)) (range 10000)))))
"Elapsed time: 87.356792 msecs"

Jackpot!

We can generate 10k IDs in serial and parallel in less than 100 ms.

💡 But wait, why is transaction implementation slow?

This question bothered me, so I decided to take another look at understanding Clojure’s LockingTransaction class.

I learned that the run method takes exclusive write locks on relevant refs and then performs the set operation. However, the lock is not granted or revoked in the following situations:

1. Timeout (100 ms) - The lock isn't acquired because another transaction held it for too long.

2. Transaction killed - An older transaction forces its way in and takes over the lock.

3. Ref’s latest value has changed - In the ensure function, even after getting the write lock, if the transaction finds that the ref was changed by another transaction that committed after this transaction's read point, it aborts and releases the lock.

Among all the points mentioned, Situation #3 causes concurrent transactions to run one after the other. Even if a transaction has made some progress, it can still abort if another transaction commits a new value. We use ensure in 7 places in our implementation, which increases the chances of a transaction being aborted.

To confirm my suspicion, I added a message in doEnsure method of the LockingTransaction class and ran the benchmark again.

void doEnsure(Ref ref){
    ...
    if(ref.tvals != null && ref.tvals.point > readPoint) {
        System.err.println("retrying...");
        ref.lock.readLock().unlock();
        throw retryex;
    }

    ...
}

In the results, it was apparent that there were too many transaction retries happening due to doEnsure method.

Now that we have identified the ensure function as the problem, let's replace it with deref. The deref function also returns the current value of the ref but does not abort the transaction.

Let’s make this change in the original implementation and run the benchmark again -

(defonce bit-lengths {:timestamp 36 :instance 8 :sequence-number 8})
(defonce bit-positions
  {:timestamp (+ (:instance bit-lengths) (:sequence-number bit-lengths))
   :instance (:sequence-number bit-lengths)
   :sequence-number 0})

(defonce max-sequence-number
  (dec (bit-shift-left 1 (:sequence-number bit-lengths))))
(defonce max-instance-number
  (dec (bit-shift-left 1 (:instance bit-lengths))))
(defonce max-timestamp
  (dec (bit-shift-left 1 (:timestamp bit-lengths))))

(defonce epoch 1704067200000) ;; 2024-01-01T00:00:00

(defonce instance-id (delay (rand-int max-instance-number)))
(defonce instance-chunk (delay (bit-shift-left (deref instance-id) (:instance bit-positions))))

(def sequence-number (ref 0))
(def last-timestamp (ref 0))


(defn- create-id [timestamp sequence-number]
  (let [time-id (- timestamp epoch)
        time-chunk (bit-shift-left time-id (:timestamp bit-positions))]
    (bit-or time-chunk @instance-chunk sequence-number)))


(defn- generate-id [now-fn]
  (dosync
   (let [current-timestamp (now-fn)]

     (when (< current-timestamp (ensure last-timestamp))
       (throw (ex-info (format "Clock moved backwards, rejecting requests for %dms"
                               (- (deref last-timestamp) current-timestamp))
                       {:current-ts current-timestamp
                        :last-ts (ensure last-timestamp)})))

     (if (= current-timestamp (deref last-timestamp))
       (if (> (deref sequence-number) max-sequence-number)
         (do ;; reset sequence number and wait for next millisecond
           (ref-set sequence-number 1)
           (let [final-timestamp
                 (loop []
                   (let [fresh-timestamp (now-fn)]
                     (if (> fresh-timestamp current-timestamp)
                       fresh-timestamp
                       (recur))))]
             (ref-set last-timestamp final-timestamp))
           (create-id (deref last-timestamp) 0))

         ;; Increment sequence number, then generate new ID
         (let [sequence-value (deref sequence-number)]
           (alter sequence-number inc)
           (create-id current-timestamp sequence-value)))

       (do
         (ref-set sequence-number 1)
         (ref-set last-timestamp current-timestamp)
         (create-id current-timestamp 0))))))


(defn get-snowflake-id
  []
  (generate-id (fn [] (System/currentTimeMillis))))

Here are the benchmarking results -

> (def ids (time (doall (cp/pmap cp-threadpool (fn [_] (get-snowflake-id)) (range 10000)))))
"Elapsed time: 248.815875 msecs"

> (def ids (time (doall (mapv (fn [_] (get-snowflake-id)) (range 10000)))))
"Elapsed time: 63.237042 msecs"

This is a massive improvement over the original implementation, although it’s still slower than the synchronized implementation.

Now, we have figured out why generating snowflake IDs was slow.

🗒️ Performance Benchmark Results

⚖️ Final Thoughts

• Clojure transactions provide the benefits of Atomicity, Isolation and Consistency, but come with a cost even if everything is running in-memory.

• Transactions shine when multiple refs are mutated across different code paths in unpredictable order.

• In contrast, when mutations follow a well-defined, sequential order, simple locking mechanisms (like locking + atom) can yield much better throughput.

• For performance-sensitive, single-responsibility code, avoiding STM may be the right trade-off.

While STM provides elegant abstractions, low-level locking mechanisms can deliver significantly better latency in tightly controlled workflows.

This debugging session was a deep dive into Clojure internals, and a rewarding one with unexpected learnings along the way. 🙂