Fork me on GitHub
#xtdb
<
2022-11-27
>
jmerrifield08:11:33

Any idea why this exact same code succeeds in a REPL but fails in a Pedestal handler?

(xt/tx-committed?
  node
  (xt/await-tx
    node
    (xt/submit-tx
      node
      [[::xt/put {:xt/id :user/test
                  :user/email ""}]])))
In the REPL it returns true and in the Pedestal handler this exception is thrown:
{:type xtdb.IllegalArgumentException
 :message "Illegal argument: ':invalid-tx'"
 :data {:xtdb.error/error-type :illegal-argument,
        :xtdb.error/error-key :invalid-tx, 
        :xtdb.error/message "Illegal argument: ':invalid-tx'",
        :tx true}
 :at [xtdb.error$illegal_arg invokeStatic "error.clj" 12]}
So it seems like the value true is getting passed into tx-committed? instead of the actual transaction

phill11:11:41

By the way, what is that code doing? It submits a transaction, then it waits for some transaction which might be a later one, then it checks whether the unknown later transaction committed?

refset12:11:47

Hey @U0EPG0ED7 I just dug through some of the code to understand where this true may have been generated from but can't find any obvious explanation. Which version of XT are you running here?

refset12:11:00

> what is that code doing? It submits a transaction, then it waits for some transaction which might be a later one The value returned from submit-tx is a kind of receipt/ticket for that specific tx, so passing it to await-tx like this means that the tx being awaited is definitely not going to be some arbitrary 'later' tx

jmerrifield16:11:46

@U899JBRPF I'm on version 1.22.1 I should have mentioned in the original post, but if I inspect the return value from await-tx it's actually a transaction as expected:

(let [tx (xt/await-tx
          node
          (xt/submit-tx
           node
           [[::xt/put {:xt/id :user/test
                       :user/email ""}]]))]
 (println "TX:" tx)
 (xt/tx-committed? node tx))
This prints: TX: {:xtdb.api/tx-id 74, :xtdb.api/tx-time #inst "2022-11-27T16:03:05.483-00:00"} then fails with the error shown above in which tx appears to be true. Again, the exact same code works in the REPL, but in a pedestal handler it looks as though the value is getting correctly returned from await-tx and then somehow changed before it hits tx-committed but I can't see any possible mechanism for that to happen!

thinking-face 1
jmerrifield16:11:16

@U0HG4EHMH the actual transaction I'm trying to submit includes a ::xt/match precondition and my understanding is that this pattern (i.e. (tx-committed? node (await-tx node (submit-tx node tx))) is the correct way to ensure that the match was satisfied and the transaction committed, before proceeding.

phill17:11:17

@U0EPG0ED7 interesting. The manual at https://docs.xtdb.com/clients/1.22.1/clojure/ says of await-tx,

"Blocks until the node has indexed a transaction that is at or past the
  supplied tx. Will throw on timeout. Returns the most recent tx indexed by the
  node."
so I would expect a race condition. Might be safer to save the return value of submit-tx with let, and use that value in both the await and the committed?, to be sure committed? answers about the transaction you meant to ask about.

jmerrifield18:11:26

Oh interesting, yes that makes sense to me! Doesn't fix the error I'm experiencing but I've updated the code as follows:

(let [submitted-tx (xt/submit-tx db my-txs)]
    (xt/await-tx db submitted-tx)
    (xt/tx-committed? db submitted-tx))

thinking-face 1
refset18:11:02

>

Returns the most recent tx indexed by the node.
Ah, of course, I forgot about that bit 😅 good spot!

👍 1
jmerrifield20:11:11

I'm fairly new to Clojure and JVM programming, is it likely to be a threading issue causing this to work in a REPL but fail inside a pedestal handler?

refset21:11:24

I certainly wouldn't rule it out, especially given Pedestal is designed around all sorts of async concepts (though I've not used it myself before), but unfortunately I can't think of an obvious explanation.

refset21:11:04

How/where is db being defined?

jmerrifield21:11:53

Right now this is just a local dev setup, this is the initialization code:

(defn start-xtdb! []
  (println "Starting XTDB")
  (letfn [(kv-store [dir]
            {:kv-store {:xtdb/module 'xtdb.rocksdb/->kv-store
                        :db-dir (io/file dir)
                        :sync? true}})]
    (xt/start-node
     {:xtdb/tx-log (kv-store "data/dev/tx-log")
      :xtdb/document-store (kv-store "data/dev/doc-store")
      :xtdb/index-store (kv-store "data/dev/index-store")})))
This is fired up by component and then injected into the request context for handlers to make use of

👍 1
jmerrifield21:11:54

Huh I didn't think this was relevant detail but my example is failing inside a Lacinia GraphQL resolver which I assumed was essentially 'just' a pedestal handler, but if I move the example code into a plain old pedestal route, it works fine

1
refset21:11:05

> In the REPL it returns true and in the Pedestal handler this exception is thrown it's there a full stacktrace?

refset21:11:37

on the off-chance it's related, try swapping ::xt/put for xtdb.api/put

jmerrifield21:11:06

This is the full stack trace:

[[xtdb.error$illegal_arg invokeStatic "error.clj" 12]
  [xtdb.error$illegal_arg invoke "error.clj" 3]
  [xtdb.error$illegal_arg invokeStatic "error.clj" 7]
  [xtdb.error$illegal_arg invoke "error.clj" 3]
  [xtdb.node.XtdbNode tx_committed_QMARK_ "node.clj" 135]
  [my-project.resolvers.mutation.test$test invokeStatic "NO_SOURCE_FILE" 69]
  [my-project.resolvers.mutation.test$test invoke "NO_SOURCE_FILE" 50]
  [com.walmartlabs.lacinia.schema$wrap_resolver_to_ensure_resolver_result$fn__8299 invoke "schema.clj" 986]
  [com.walmartlabs.lacinia.executor$invoke_resolver_for_field invokeStatic "executor.clj" 89]
  [com.walmartlabs.lacinia.executor$invoke_resolver_for_field invoke "executor.clj" 68]
  [com.walmartlabs.lacinia.executor$resolve_and_select invokeStatic "executor.clj" 353]
  [com.walmartlabs.lacinia.executor$resolve_and_select invoke "executor.clj" 234]
  [com.walmartlabs.lacinia.executor$apply_field_selection invokeStatic "executor.clj" 140]
  [com.walmartlabs.lacinia.executor$apply_field_selection invoke "executor.clj" 135]
  [com.walmartlabs.lacinia.executor$apply_selection invokeStatic "executor.clj" 173]
  [com.walmartlabs.lacinia.executor$apply_selection invoke "executor.clj" 165]
  [com.walmartlabs.lacinia.executor$combine_selection_results_sync$fn__31254 invoke "executor.clj" 212]
  [com.walmartlabs.lacinia.resolve.ResolverResultImpl on_deliver_BANG_ "resolve.clj" 135]
  [com.walmartlabs.lacinia.executor$combine_selection_results_sync invokeStatic "executor.clj" 208]
  [com.walmartlabs.lacinia.executor$combine_selection_results_sync invoke "executor.clj" 203]
  [com.walmartlabs.lacinia.executor$execute_nested_selections_sync$fn__31261 invoke "executor.clj" 230]
  [clojure.lang.ArrayChunk reduce "ArrayChunk.java" 58]
  [clojure.core.protocols$fn__8176 invokeStatic "protocols.clj" 136]
  [clojure.core.protocols$fn__8176 invoke "protocols.clj" 124]
  [clojure.core.protocols$fn__8136$G__8131__8145 invoke "protocols.clj" 19]
  [clojure.core.protocols$seq_reduce invokeStatic "protocols.clj" 31]
  [clojure.core.protocols$fn__8168 invokeStatic "protocols.clj" 75]
  [clojure.core.protocols$fn__8168 invoke "protocols.clj" 75]
  [clojure.core.protocols$fn__8110$G__8105__8123 invoke "protocols.clj" 13]
  [clojure.core$reduce invokeStatic "core.clj" 6830]
  [clojure.core$reduce invoke "core.clj" 6812]
  [com.walmartlabs.lacinia.executor$execute_nested_selections_sync invokeStatic "executor.clj" 230]
  [com.walmartlabs.lacinia.executor$execute_nested_selections_sync invoke "executor.clj" 221]
  [com.walmartlabs.lacinia.executor$execute_query$fn__31286 invoke "executor.clj" 400]
  [clojure.lang.AFn applyToHelper "AFn.java" 152]
  [clojure.lang.AFn applyTo "AFn.java" 144]
  [clojure.core$apply invokeStatic "core.clj" 667]
  [clojure.core$with_bindings_STAR_ invokeStatic "core.clj" 1977]
  [clojure.core$with_bindings_STAR_ doInvoke "core.clj" 1977]
  [clojure.lang.RestFn invoke "RestFn.java" 425]
  [clojure.lang.AFn applyToHelper "AFn.java" 156]
  [clojure.lang.RestFn applyTo "RestFn.java" 132]
  [clojure.core$apply invokeStatic "core.clj" 671]
  [clojure.core$bound_fn_STAR_$fn__5767 doInvoke "core.clj" 2007]
  [clojure.lang.RestFn invoke "RestFn.java" 397]
  [com.walmartlabs.lacinia.executor$execute_query$fn__31291 invoke "executor.clj" 421]
  [clojure.core$binding_conveyor_fn$fn__5772 invoke "core.clj" 2034]
  [clojure.lang.AFn call "AFn.java" 18]
  [java.util.concurrent.FutureTask run "FutureTask.java" 266]
  [java.util.concurrent.ThreadPoolExecutor runWorker "ThreadPoolExecutor.java" 1149]
  [java.util.concurrent.ThreadPoolExecutor$Worker run "ThreadPoolExecutor.java" 624]
  [java.lang.Thread run "Thread.java" 748]]}, :line 191}

🙏 1
jmerrifield22:11:42

No difference if I replace ::xt/put with :xtdb.api/put

👌 1
refset22:11:55

no clues that I can see there, sadly. And I've not used Lacinia either

jmerrifield22:11:33

I think I've figured it out and it looks like a dumb late-night coding error. There was a second call to tx-committed? left over in my code from an earlier exploration which wasn't receiving the correct transaction, and that was the source of the exception, not the code I posted facepalm Had I paid more attention to the trace I might have noticed the discrepancy! Sorry for the wild goose chase, and thank you for the support! And I'm glad I at least know to use the return value from submit-tx instead of await-tx in future.

refset22:11:19

Ahh, you're most welcome, these things happen! I'm very glad you got to the bottom of it 🙂