search

fluree / core

Fluree releases and public bug reports
0 stars 0 forks source link

Using an unbound `?var` in `insert` causes an uncaught exception #60

Closed aaj3f closed 7 months ago

aaj3f commented 7 months ago

Description

Using a ?var in an index that isn't declared in your where clause causes an uncaught exception and a hanging, non-response from the HTTP API

For example,

{
    "@context": "https://ns.flur.ee/",
    "ledger": "cookbook/base",
    "insert": {
        "@id": "ex:mosquitos", 
        "schema:description": "?x"
    }
}

Produces this in the logs for server

18:18:57.628 [qtp1343222554-30] DEBUG fluree.server.components.http - Unwrapped credential with did: nil
18:18:57.748 [async-dispatch-4] DEBUG fluree.db.json-ld.api - Looking up address for ledger alias "cookbook/base"
18:18:57.748 [async-dispatch-5] DEBUG fluree.db.json-ld.api - exists? - ledger address: "fluree:file://cookbook/base/main/head"
18:18:57.779 [async-dispatch-4] DEBUG f.s.components.consensus-handler - New consensus event: :tx-queue {:txn {"https://ns.flur.ee/ledger#insert" [{"@value" {"schema:description" "?x", "@id" "ex:mosquitos"}, "@type" "@json"}], "https://ns.flur.ee/ledger#ledger" [{"@value" "cookbook/base"}]}, :conn-type :file, :size 2, :tx-id "0dbc2010bc14bfb667c452f126bdbdbdfb24c90317808fef27d3d08f2ea28d28", :ledger-id "cookbook/base", :txn-context :fluree.db.dbproto/default-context, :opts nil, :instant 1699985937765}
18:18:57.779 [async-dispatch-4] DEBUG f.server.consensus.handlers.tx-queue - Queuing new transaction into state machine with params:  {:txn {"https://ns.flur.ee/ledger#insert" [{"@value" {"schema:description" "?x", "@id" "ex:mosquitos"}, "@type" "@json"}], "https://ns.flur.ee/ledger#ledger" [{"@value" "cookbook/base"}]}, :conn-type :file, :size 2, :tx-id "0dbc2010bc14bfb667c452f126bdbdbdfb24c90317808fef27d3d08f2ea28d28", :ledger-id "cookbook/base", :txn-context :fluree.db.dbproto/default-context, :opts nil, :instant 1699985937765}
18:18:57.779 [clojure-agent-send-off-pool-6] DEBUG f.s.components.consensus-handler - Executing consensus processor fn: :tx-queue {:txn {"https://ns.flur.ee/ledger#insert" [{"@value" {"schema:description" "?x", "@id" "ex:mosquitos"}, "@type" "@json"}], "https://ns.flur.ee/ledger#ledger" [{"@value" "cookbook/base"}]}, :conn-type :file, :size 2, :tx-id "0dbc2010bc14bfb667c452f126bdbdbdfb24c90317808fef27d3d08f2ea28d28", :ledger-id "cookbook/base", :txn-context :fluree.db.dbproto/default-context, :opts nil, :instant 1699985937765}
18:18:57.779 [clojure-agent-send-off-pool-6] DEBUG f.server.consensus.handlers.tx-queue - Starting transaction processing for ledger: "cookbook/base" with tx-id "0dbc2010bc14bfb667c452f126bdbdbdfb24c90317808fef27d3d08f2ea28d28" . Transaction sat in queue for 14 milliseconds.
18:18:57.779 [async-dispatch-3] DEBUG fluree.db.json-ld.api - Looking up address for ledger alias "cookbook/base"
18:18:57.779 [async-dispatch-3] DEBUG fluree.db.json-ld.api - exists? - ledger address: "fluree:file://cookbook/base/main/head"
18:18:57.780 [async-dispatch-7] DEBUG fluree.db.conn.core - Registering ledger:  "cookbook/base"  not-cached?  true
18:18:57.785 [async-dispatch-6] DEBUG fluree.db.ledger.json-ld - load commit: {"https://ns.flur.ee/ledger#ns" [{:idx ["ns" 0], :id "fluree:file://cookbook/base/main/head"}], "https://ns.flur.ee/ledger#branch" [{:value "main", :type nil, :idx ["branch"]}], "https://ns.flur.ee/ledger#previous" [{:idx ["previous"], :type ["https://ns.flur.ee/ledger#Commit"], "https://ns.flur.ee/ledger#address" [{:value "fluree:file://cookbook/base/main/commit/244a805eec95919ad70233fcb6f390ef161adfe32202a825a71d3119de0cf849.json", :type nil, :idx ["previous" "address"]}], :id "fluree:commit:sha256:bwnokcclyq3layxfaoeeaqpabu5sj7yftbjqxfc64zpyyvpnqcxr"}], "https://ns.flur.ee/ledger#address" [{:value "fluree:file://cookbook/base/main/commit/abea7bf0119131976cb916db7c8f580c259862464872a5c8d2516cd52bbcbb2d.json", :type nil, :idx ["address"]}], :type ["https://ns.flur.ee/ledger#Commit"], "https://ns.flur.ee/ledger#alias" [{:value "cookbook/base", :type nil, :idx ["alias"]}], "https://ns.flur.ee/ledger#v" [{:value 0, :type "http://www.w3.org/2001/XMLSchema#decimal", :idx ["v"]}], "https://ns.flur.ee/ledger#defaultContext" [{:idx ["defaultContext"], :type ["https://ns.flur.ee/ledger#Context"], "https://ns.flur.ee/ledger#address" [{:value "fluree:file://cookbook/base/main/context/b16965119d05f836e6a1e221730adf5db0b7212c831a3f83aa52e449fe7ce6ef.json", :type nil, :idx ["defaultContext" "address"]}], :id "fluree:context:b16965119d05f836e6a1e221730adf5db0b7212c831a3f83aa52e449fe7ce6ef"}], "https://ns.flur.ee/ledger#time" [{:value "2023-11-14T18:18:06.697171880Z", :type nil, :idx ["time"]}], :id "fluree:commit:sha256:bu73q2kg3h4knwyzmrqlys22usiwgmltrfkruc4gioysehujuign", :idx [], "https://ns.flur.ee/ledger#data" [{:idx ["data"], :type ["https://ns.flur.ee/ledger#DB"], "https://ns.flur.ee/ledger#address" [{:value "fluree:file://cookbook/base/main/commit/793cfb667b1b72ce4032d48ab42e34e203a61bec75b4cb29e136cb9b9fbcbe9b.json", :type nil, :idx ["data" "address"]}], "https://ns.flur.ee/ledger#flakes" [{:value 149, :type "http://www.w3.org/2001/XMLSchema#long", :idx ["data" "flakes"]}], :id "fluree:db:sha256:bbbkn3ohokv5x54qxkkrt37hogwe37cbozpx2t3rpjkn4q4vmkmk5", "https://ns.flur.ee/ledger#previous" [{:idx ["data" "previous"], :type ["https://ns.flur.ee/ledger#DB"], "https://ns.flur.ee/ledger#address" [{:value "fluree:file://cookbook/base/main/commit/8e4c69586c1872e542f8804fe35d29db453ac0a50ba9c83e68c0381ea4786543.json", :type nil, :idx ["data" "previous" "address"]}], :id "fluree:db:sha256:bbqgxfukhtpkesykfc23l5ww5tvhicl53eky3rfv22tgmrqhccxip"}], "https://ns.flur.ee/ledger#size" [{:value 13077, :type "http://www.w3.org/2001/XMLSchema#long", :idx ["data" "size"]}], "https://ns.flur.ee/ledger#t" [{:value 6, :type "http://www.w3.org/2001/XMLSchema#long", :idx ["data" "t"]}]}], "https://ns.flur.ee/ledger#index" [{:idx ["index"], :type ["https://ns.flur.ee/ledger#Index"], "https://ns.flur.ee/ledger#address" [{:value "fluree:file://cookbook/base/main/index/root/779ae12264c2b9d45e81800b43c0a22b75bf0c3d4a4899f081c5508b1288c481.json", :type nil, :idx ["index" "address"]}], "https://ns.flur.ee/ledger#data" [{:idx ["index" "data"], :type ["https://ns.flur.ee/ledger#DB"], "https://ns.flur.ee/ledger#address" [{:value "fluree:file://cookbook/base/main/commit/793cfb667b1b72ce4032d48ab42e34e203a61bec75b4cb29e136cb9b9fbcbe9b.json", :type nil, :idx ["index" "data" "address"]}], "https://ns.flur.ee/ledger#flakes" [{:value 149, :type "http://www.w3.org/2001/XMLSchema#long", :idx ["index" "data" "flakes"]}], :id "fluree:db:sha256:bbbkn3ohokv5x54qxkkrt37hogwe37cbozpx2t3rpjkn4q4vmkmk5", "https://ns.flur.ee/ledger#previous" [{:idx ["index" "data" "previous"], ":address" [{:value "fluree:file://cookbook/base/main/commit/8e4c69586c1872e542f8804fe35d29db453ac0a50ba9c83e68c0381ea4786543.json", :type nil, :idx ["index" "data" "previous" ":address"]}], ":id" [{:value "fluree:db:sha256:bbqgxfukhtpkesykfc23l5ww5tvhicl53eky3rfv22tgmrqhccxip", :type nil, :idx ["index" "data" "previous" ":id"]}]}], "https://ns.flur.ee/ledger#size" [{:value 13077, :type "http://www.w3.org/2001/XMLSchema#long", :idx ["index" "data" "size"]}], "https://ns.flur.ee/ledger#t" [{:value 6, :type "http://www.w3.org/2001/XMLSchema#long", :idx ["index" "data" "t"]}]}], :id "fluree:index:sha256:779ae12264c2b9d45e81800b43c0a22b75bf0c3d4a4899f081c5508b1288c481"}]}
18:18:57.785 [async-dispatch-6] DEBUG fluree.db.json-ld.reify - loading default context from storage w/ address: "fluree:file://cookbook/base/main/context/b16965119d05f836e6a1e221730adf5db0b7212c831a3f83aa52e449fe7ce6ef.json"
18:18:57.811 [async-dispatch-4] DEBUG fluree.db.json-ld.reify - load-db-idx commit-map: {:address "fluree:file://cookbook/base/main/commit/abea7bf0119131976cb916db7c8f580c259862464872a5c8d2516cd52bbcbb2d.json", :v 0, :index {:id "fluree:index:sha256:779ae12264c2b9d45e81800b43c0a22b75bf0c3d4a4899f081c5508b1288c481", :address "fluree:file://cookbook/base/main/index/root/779ae12264c2b9d45e81800b43c0a22b75bf0c3d4a4899f081c5508b1288c481.json", :data {:id "fluree:db:sha256:bbbkn3ohokv5x54qxkkrt37hogwe37cbozpx2t3rpjkn4q4vmkmk5", :t 6, :address "fluree:file://cookbook/base/main/commit/793cfb667b1b72ce4032d48ab42e34e203a61bec75b4cb29e136cb9b9fbcbe9b.json", :flakes 149, :size 13077}, :spot {:leaf false, :size 14467, :leftmost? true, :ledger-alias nil, :id "fluree:file://cookbook/base/main/index/spot/5eddd09ae4f5967295c39c6944402e5d0832ebe72616b5fe18529be5e201b455.json", :comparator #object[fluree.db.flake$cmp_flakes_spot 0x42c7059b "fluree.db.flake$cmp_flakes_spot@42c7059b"], :t -6, :first #Flake [211106232533001 0 "http://example.org/Monster" 1 -2 true nil], :rhs nil}, :post {:leaf false, :size 14467, :leftmost? true, :ledger-alias nil, :id "fluree:file://cookbook/base/main/index/post/166962129f23b0e0220029c0305321eb1cfcbcfd6c0f1958b929b30485c2ed64.json", :comparator #object[fluree.db.flake$cmp_flakes_post 0x77d8b66f "fluree.db.flake$cmp_flakes_post@77d8b66f"], :t -6, :first #Flake [0 0 "@id" 1 -1 true nil], :rhs nil}, :opst {:leaf false, :size 2000, :leftmost? true, :ledger-alias nil, :id "fluree:file://cookbook/base/main/index/opst/1e531f6d8aaecb729e4209edefa5fabc90ef15439f46b77245d7a3e3b93a41e8.json", :comparator #object[fluree.db.flake$cmp_flakes_opst 0x6a59ce4a "fluree.db.flake$cmp_flakes_opst@6a59ce4a"], :t -6, :first #Flake [-2 52 nil 0 -2 true nil], :rhs nil}, :tspo {:leaf false, :size 14467, :leftmost? true, :ledger-alias nil, :id "fluree:file://cookbook/base/main/index/tspo/ce11baf360b51bd055a644364c25c9343020337bb17aff23d5167f476a3323f7.json", :comparator #object[fluree.db.flake$cmp_flakes_block 0x26b877c8 "fluree.db.flake$cmp_flakes_block@26b877c8"], :t -6, :first #Flake [211106232532996 0 "http://schema.org/Person" 1 -1 true nil], :rhs nil}}, :ns [{:id "fluree:file://cookbook/base/main/head"}], :time "2023-11-14T18:18:06.697171880Z", :defaultContext {:id "fluree:context:b16965119d05f836e6a1e221730adf5db0b7212c831a3f83aa52e449fe7ce6ef", :type ["https://ns.flur.ee/ledger#Context"], :address "fluree:file://cookbook/base/main/context/b16965119d05f836e6a1e221730adf5db0b7212c831a3f83aa52e449fe7ce6ef.json"}, :alias "cookbook/base", :previous {:id "fluree:commit:sha256:bwnokcclyq3layxfaoeeaqpabu5sj7yftbjqxfc64zpyyvpnqcxr", :address "fluree:file://cookbook/base/main/commit/244a805eec95919ad70233fcb6f390ef161adfe32202a825a71d3119de0cf849.json"}, :id "fluree:commit:sha256:bu73q2kg3h4knwyzmrqlys22usiwgmltrfkruc4gioysehujuign", :tag [], :branch "main", :message nil, :data {:id "fluree:db:sha256:bbbkn3ohokv5x54qxkkrt37hogwe37cbozpx2t3rpjkn4q4vmkmk5", :t 6, :address "fluree:file://cookbook/base/main/commit/793cfb667b1b72ce4032d48ab42e34e203a61bec75b4cb29e136cb9b9fbcbe9b.json", :flakes 149, :size 13077}}
18:18:57.812 [async-dispatch-4] DEBUG fluree.db.ledger.json-ld - Attempting to update ledger's db with new commit: "cookbook/base" branch: :main
18:18:57.847 [async-dispatch-4] ERROR fluree.db.query.exec.update - Error inserting new triple
java.lang.NullPointerException: Cannot invoke "java.lang.Character.charValue()" because "x" is null
        at clojure.lang.RT.intCast(RT.java:1221)
        at fluree.db.datatype$coerce.invokeStatic(datatype.cljc:333)
        at fluree.db.datatype$coerce.invoke(datatype.cljc:324)
        at fluree.db.datatype$coerce_value.invokeStatic(datatype.cljc:413)
        at fluree.db.datatype$coerce_value.invoke(datatype.cljc:408)
        at fluree.db.query.exec.update$insert_triple2$fn__30502$state_machine__14707__auto____30521$fn__30524.invoke(update.cljc:245)
        at fluree.db.query.exec.update$insert_triple2$fn__30502$state_machine__14707__auto____30521.invoke(update.cljc:199)
        at clojure.core.async.impl.ioc_macros$run_state_machine.invokeStatic(ioc_macros.clj:972)
        at clojure.core.async.impl.ioc_macros$run_state_machine.invoke(ioc_macros.clj:971)
        at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invokeStatic(ioc_macros.clj:976)
        at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invoke(ioc_macros.clj:974)
        at clojure.core.async.impl.ioc_macros$take_BANG_$fn__14725.invoke(ioc_macros.clj:985)
        at clojure.core.async.impl.channels.ManyToManyChannel$fn__9768$fn__9769.invoke(channels.clj:100)
        at clojure.lang.AFn.run(AFn.java:22)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at clojure.core.async.impl.concurrent$counted_thread_factory$reify__9671$fn__9672.invoke(concurrent.clj:29)
        at clojure.lang.AFn.run(AFn.java:22)
        at java.base/java.lang.Thread.run(Unknown Source)
Exception in thread "async-dispatch-4" java.lang.IllegalArgumentException: Don't know how to create ISeq from: java.lang.Boolean
        at clojure.lang.RT.seqFrom(RT.java:557)
        at clojure.lang.RT.seq(RT.java:537)
        at clojure.core$seq__5467.invokeStatic(core.clj:139)
        at clojure.core.protocols$seq_reduce.invokeStatic(protocols.clj:24)
        at clojure.core.protocols$fn__8226.invokeStatic(protocols.clj:75)
        at clojure.core.protocols$fn__8226.invoke(protocols.clj:75)
        at clojure.core.protocols$fn__8178$G__8173__8191.invoke(protocols.clj:13)
18:18:57.850 [async-dispatch-8] ERROR fluree.db.json-ld.api - #error {
 :cause "Cannot invoke \"java.lang.Character.charValue()\" because \"x\" is null"
 :via
 [{:type java.lang.NullPointerException
   :message "Cannot invoke \"java.lang.Character.charValue()\" because \"x\" is null"
   :at [clojure.lang.RT intCast "RT.java" 1221]}]
 :trace
 [[clojure.lang.RT intCast "RT.java" 1221]
  [fluree.db.datatype$coerce invokeStatic "datatype.cljc" 333]
  [fluree.db.datatype$coerce invoke "datatype.cljc" 324]
  [fluree.db.datatype$coerce_value invokeStatic "datatype.cljc" 413]
  [fluree.db.datatype$coerce_value invoke "datatype.cljc" 408]
  [fluree.db.query.exec.update$insert_triple2$fn__30502$state_machine__14707__auto____30521$fn__30524 invoke "update.cljc" 245]
  [fluree.db.query.exec.update$insert_triple2$fn__30502$state_machine__14707__auto____30521 invoke "update.cljc" 199]
  [clojure.core.async.impl.ioc_macros$run_state_machine invokeStatic "ioc_macros.clj" 972]
  [clojure.core.async.impl.ioc_macros$run_state_machine invoke "ioc_macros.clj" 971]
  [clojure.core.async.impl.ioc_macros$run_state_machine_wrapped invokeStatic "ioc_macros.clj" 976]
  [clojure.core.async.impl.ioc_macros$run_state_machine_wrapped invoke "ioc_macros.clj" 974]
  [clojure.core.async.impl.ioc_macros$take_BANG_$fn__14725 invoke "ioc_macros.clj" 985]
  [clojure.core.async.impl.channels.ManyToManyChannel$fn__9768$fn__9769 invoke "channels.clj" 100]
  [clojure.lang.AFn run "AFn.java" 22]
  [java.util.concurrent.ThreadPoolExecutor runWorker nil -1]
  [java.util.concurrent.ThreadPoolExecutor$Worker run nil -1]
  [clojure.core.async.impl.concurrent$counted_thread_factory$reify__9671$fn__9672 invoke "concurrent.clj" 29]
  [clojure.lang.AFn run "AFn.java" 22]
  [java.lang.Thread run nil -1]]}
        at clojure.core$reduce.invokeStatic(core.clj:6886)
        at clojure.core$into.invokeStatic(core.clj:6958)
        at clojure.core$into.invoke(core.clj:6950)
        at clojure.core.async$reduce$fn__15551$state_machine__14707__auto____15558$fn__15560.invoke(async.clj:643)
        at clojure.core.async$reduce$fn__15551$state_machine__14707__auto____15558.invoke(async.clj:643)
        at clojure.core.async.impl.ioc_macros$run_state_machine.invokeStatic(ioc_macros.clj:972)
        at clojure.core.async.impl.ioc_macros$run_state_machine.invoke(ioc_macros.clj:971)
        at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invokeStatic(ioc_macros.clj:976)
        at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invoke(ioc_macros.clj:974)
        at clojure.core.async.impl.ioc_macros$take_BANG_$fn__14725.invoke(ioc_macros.clj:985)
        at clojure.core.async.impl.channels.ManyToManyChannel$fn__9768$fn__9769.invoke(channels.clj:100)
        at clojure.lang.AFn.run(AFn.java:22)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at clojure.core.async.impl.concurrent$counted_thread_factory$reify__9671$fn__9672.invoke(concurrent.clj:29)
        at clojure.lang.AFn.run(AFn.java:22)
        at java.base/java.lang.Thread.run(Unknown Source)
18:18:57.862 [async-dispatch-2] DEBUG f.s.components.consensus-handler - New consensus event: :tx-exception {:ledger-id "cookbook/base", :ex-message "Cannot invoke \"java.lang.Character.charValue()\" because \"x\" is null", :ex-data nil, :tx-id "0dbc2010bc14bfb667c452f126bdbdbdfb24c90317808fef27d3d08f2ea28d28", :server "/ip4/127.0.0.1/tcp/62071"}
18:18:57.862 [async-dispatch-2] DEBUG f.s.consensus.handlers.tx-exception - "Transaction exception received via consensus: {:ledger-id \"cookbook/base\", :ex-message \"Cannot invoke \\\"java.lang.Character.charValue()\\\" because \\\"x\\\" is null\", :ex-data nil, :tx-id \"0dbc2010bc14bfb667c452f126bdbdbdfb24c90317808fef27d3d08f2ea28d28\", :server \"/ip4/127.0.0.1/tcp/62071\"}"
18:18:57.862 [async-dispatch-2] DEBUG f.s.consensus.handlers.tx-exception - Delivering tx-exception to watcher with msg/data:  "Cannot invoke \"java.lang.Character.charValue()\" because \"x\" is null" nil
18:18:57.862 [async-dispatch-2] WARN  f.s.consensus.handlers.tx-exception - "Error recording transaction exception: Additional data must be non-nil."
cap10morgan commented 7 months ago

@aaj3f What's the expected / desired behavior here? Just an understandable error response and no hanging?

cap10morgan commented 7 months ago

@aaj3f Oh, also, did you try this without the trailing slash in the @context value (i.e. "https://ns.flur.ee")? It requires that there not be one.

aaj3f commented 7 months ago

@cap10morgan oh, yes, sorry.... I actually don't know how it ended up in the example above, but it wasn't in the request I sent

aaj3f commented 7 months ago

I think if a ?var is used in insert that isn't already defined in where (or if there is no where) then we should throw some parse error for using a ?var not defined in the where clause -- I think we already do this in queries, for example

cap10morgan commented 7 months ago

Fix PR: https://github.com/fluree/db/pull/681

cap10morgan commented 7 months ago

New fix PR: https://github.com/fluree/db/pull/692