debug

caching/src/immutant/caching.clj

@@ -141,6 +141,13 @@
       (:ttl options -1)
       (:idle options -1))))
 
+(let [serializer (java.util.concurrent.Executors/newSingleThreadExecutor)]
+  (defn mark [& msg]
+    (let [^Runnable r #(apply println
+                         (.format (java.text.SimpleDateFormat. "HH:mm:ss,SSS")
+                           (java.util.Date.)) msg)]
+      (.submit serializer r))))
+
 (defn swap-in!
   "Atomically swaps the value associated to the key in the cache with
   the result of applying f, passing the current value as the first
@@ -149,15 +156,22 @@
   If the key is missing, the result of applying f to nil will be
   inserted atomically."
   [^org.infinispan.Cache cache key f & args]
+  (mark "SWAP-IN started")
   (loop [val (get cache key)]
+    (mark "SWAP-IN in loop")
     (let [new (apply f val args)]
+      (mark "SWAP-IN post apply")
       (if (or val (contains? cache key))
-        (if (.replace cache key val new)
-          new
-          (recur (get cache key)))
-        (if (nil? (.putIfAbsent cache key new))
-          new
-          (recur (get cache key)))))))
+        (let [v (.replace cache key val new)]
+          (mark "SWAP-IN post replace")
+          (if v
+            new
+            (recur (get cache key))))
+        (let [v (.putIfAbsent cache key new)]
+          (mark "SWAP-IN post putIfAbsent")
+          (if (nil? v)
+            new
+            (recur (get cache key))))))))
 
 (defn exists?
   "Return true if the named cache exists"

transactions/test/immutant/transactions_test.clj

@@ -62,15 +62,23 @@
     :c
     int))
 
+(def mark csh/mark)
+
 (defn work [m]
+  (mark "MESSAGE RCVD" m)
   (csh/swap-in! cache :a (constantly 1))
+  (mark "SWAPPED")
   (msg/publish queue "kiwi")
+  (mark "PUBLISHED kiwi")
   (msg/publish remote-queue "starfruit")
+  (mark "PUBLISHED starfruit")
   (not-supported
     (csh/swap-in! cache :deliveries (fnil inc 0)))
+  (mark "UPDATED :deliveries")
   (sql/with-db-transaction [t spec]
+    (mark "WRITING TO DB")
     (write-thing-to-db t "tangerine")
-    (when (:throw? m) (throw (Exception. "rollback")))
+    (when (:throw? m) (mark "THROWING") (throw (Exception. "rollback")))
     (when (:rollback? m)
       (set-rollback-only)
       (sql/db-set-rollback-only! t))))
@@ -154,11 +162,13 @@
 (deftest non-transactional-writes-in-listener-with-exception
   (with-open [_ (msg/listen trigger listener :mode :auto-ack)]
     (msg/publish trigger {:throw? true})
+    (mark "MESSAGE SENT")
     (is (= 10 (loop [i 0]
                 (Thread/sleep 100)
                 (if (or (= 50 i) (= 10 (:deliveries cache)))
                   (:deliveries cache)
                   (recur (inc i))))))
+    (mark "LOOP DONE")
     (is (= 1 (:a cache)))
     (is (= (repeat 10 "kiwi")      (repeatedly 10 #(msg/receive queue))))
     (is (= (repeat 10 "starfruit") (repeatedly 10 #(msg/receive local-remote-queue))))))