replikativ / datahike

A fast, immutable, distributed & compositional Datalog engine for everyone.
https://datahike.io
Eclipse Public License 1.0
1.62k stars 95 forks source link

Fixed reflection in with-precision and abs #671

Closed mokshasoft closed 2 months ago

mokshasoft commented 4 months ago

SUMMARY

Fix reflection warnings in order to speed up execution.

Checks

I've run the following tests (Sometimes the tests fail non-deterministically): bb test clj-pss bb test specs bb test integration bb test clj-hht

I've also run our performance test suite that didn't show any improvements. https://gitlab.com/arbetsformedlingen/taxonomy-dev/backend/experimental/datahike-benchmark

Bugfix
whilo commented 2 months ago

Hey @mokshasoft, Thanks for opening this issue! Can you report how the tests failed? This should not happen.

mokshasoft commented 2 months ago

I just run the tests over and over again like this:

datahike % git log -1
commit efc6109923c0eaccd73f2098493f368d6ab9896c (HEAD -> main, tag: 0.6.1558, origin/main, origin/HEAD)
Author: Timo Kramer <4785848+TimoKramer@users.noreply.github.com>
Date:   Wed Feb 14 07:56:47 2024 +0100

    add resources to http-server-clj src-dirs jvm build configuration (#665)

    Authored-by: Bruno do Nascimento Maciel <brunodonascimentomaciel@gmail.com>

    Fixes #663
datahike % while [ true ] ; do  bb test clj-pss ; done 2>&1 | grep failures
305 tests, 1678 assertions, 0 failures.
305 tests, 1678 assertions, 0 failures.
305 tests, 1678 assertions, 0 failures.
305 tests, 1678 assertions, 1 errors, 0 failures.
1 tests, 1 assertions, 1 errors, 0 failures.
305 tests, 1678 assertions, 0 failures.
305 tests, 1678 assertions, 0 failures.
^C
mokshasoft commented 2 months ago

Here's one such specific failure:

datahike.test.attribute-refs.query-or-test
  test-or
  test-or-join
  test-default-source
  test-errors

Randomized with --seed 1068925775

ERROR in datahike.test.time-variance-test/test-as-of-db (utils.cljc:141)
get values at specific time
Exception: clojure.lang.ExceptionInfo: Nothing found for entity id [:name "Alice"]
{:error :entity-id/missing, :entity-id [:name "Alice"]}
 at datahike.db.utils$entid_strict.invokeStatic (utils.cljc:141)
    datahike.db.utils$entid_strict.invoke (utils.cljc:136)
    datahike.query$resolve_pattern_lookup_entity_id.invokeStatic (query.cljc:936)
    datahike.query$resolve_pattern_lookup_entity_id.invoke (query.cljc:934)
    datahike.query$resolve_pattern_lookup_refs.invokeStatic (query.cljc:947)
    datahike.query$resolve_pattern_lookup_refs.invoke (query.cljc:941)
    datahike.query$resolve_pattern_lookup_refs.invokeStatic (query.cljc:943)
    datahike.query$resolve_pattern_lookup_refs.invoke (query.cljc:941)
    datahike.query$_resolve_clause_STAR_.invokeStatic (query.cljc:1283)
    datahike.query$_resolve_clause_STAR_.invoke (query.cljc:1186)
    datahike.query$_resolve_clause$fn__40927.invoke (query.cljc:1293)
    datahike.query_stats$update_ctx_with_stats.invokeStatic (query_stats.cljc:31)
    datahike.query_stats$update_ctx_with_stats.invoke (query_stats.cljc:19)
    datahike.query$_resolve_clause.invokeStatic (query.cljc:1292)
    datahike.query$_resolve_clause.invoke (query.cljc:1288)
    datahike.query$_resolve_clause.invokeStatic (query.cljc:1290)
    datahike.query$_resolve_clause.invoke (query.cljc:1288)
    datahike.query$resolve_clause.invokeStatic (query.cljc:1302)
    datahike.query$resolve_clause.invoke (query.cljc:1295)
    ...
    datahike.query$_q.invokeStatic (query.cljc:1306)
    datahike.query$_q.invoke (query.cljc:1304)
    datahike.query$raw_q.invokeStatic (query.cljc:1444)
    datahike.query$raw_q.invoke (query.cljc:1432)
    datahike.query$q.invokeStatic (query.cljc:81)
    datahike.query$q.doInvoke (query.cljc:75)
    ...
    datahike.test.time_variance_test$fn__63125$fn__63126.invoke (time_variance_test.cljc:127)
    datahike.test.time_variance_test$fn__63125.invokeStatic (time_variance_test.cljc:125)
    datahike.test.time_variance_test/fn (time_variance_test.cljc:115)
    ...
╭───── Test output ───────────────────────────────────────────────────────
│ 2024-06-14T13:33:00.447Z 98-38159 ERROR [datahike.db.utils:141] - Nothing found for entity id  [:name "Alice"] {:error :entity-id/missing, :entity-id [:name "Alice"]}
╰─────────────────────────────────────────────────────────────────────────
307 tests, 1689 assertions, 1 errors, 0 failures.
----- Error --------------------------------------------------------------------
Type:     clojure.lang.ExceptionInfo
Message:  
Data:     {:proc #object[java.lang.ProcessImpl 0x5af2b201 "Process[pid=92938, exitValue=1]"], :exit 1, :in #object[java.lang.ProcessBuilder$NullOutputStream 0x1f004aab "java.lang.ProcessBuilder$NullOutputStream@1f004aab"], :out #object[java.lang.ProcessBuilder$NullInputStream 0x299cfe74 "java.lang.ProcessBuilder$NullInputStream@299cfe74"], :err #object[java.lang.ProcessBuilder$NullInputStream 0x299cfe74 "java.lang.ProcessBuilder$NullInputStream@299cfe74"], :prev nil, :cmd ["clojure" "-M:test" "-m" "kaocha.runner" "--focus" "clj-pss"], :type :babashka.process/error}
Location: /Users/clajo/Repos/JobTech/forks/datahike/bb/src/tools/test.clj:7:25

----- Context ------------------------------------------------------------------
 3:   (:require [babashka.fs :as fs]
 4:             [babashka.process :as p]
 5:             [tools.build :as build]))
 6: 
 7: (defn clj [opts & args] (apply p/shell opts "clojure" args))
                            ^--- 
 8: (defn git [opts & args] (apply p/shell opts "git" args))
 9: 
10: (defn kaocha [& args]
11:   (apply clj {:extra-env {"TIMBRE_LEVEL" ":warn"}}
12:          "-M:test" "-m" "kaocha.runner" args))

----- Stack trace --------------------------------------------------------------
babashka.process/check                    - <built-in>
babashka.process/shell                    - <built-in>
clojure.core/apply                        - <built-in>
babashka.impl.process/shell               - <built-in>
clojure.core/apply                        - <built-in>
... (run with --debug to see elided elements)
tools.test                                - /Users/clajo/Repos/JobTech/forks/datahike/bb/src/tools/test.clj:11:3
clojure.core/apply                        - <built-in>
tools.test                                - /Users/clajo/Repos/JobTech/forks/datahike/bb/src/tools/test.clj:74:7
clojure.core/apply                        - <built-in>
user-d01b4620-4395-44fd-a47c-2e9bb9e531bd - /Users/clajo/Repos/JobTech/Datahike/datahike/test:36:1
whilo commented 2 months ago

Thank you! This is happening because somehow the transaction is executed after the timestamp is set in test-as-of-db, you can see the sleep call in the code there to make sure that the test runs after the data is transacted, but there is no guarantee for that. An alternative would be to extract the transaction timestamp from the transact call or we could also increase the timeout. But these failures are benign, they are just bad because they create confusion like this.