Hello,
I have a database that has reach a state where reads are working normally but every transaction throws a nullpointerexception with the following report (also part of log below):
{:clojure.main/message
"Execution error (NullPointerException) at user/eval333$fn (REPL:-1).\njava.lang.NullPointerException\n",
:clojure.main/triage
{:clojure.error/class java.lang.NullPointerException,
:clojure.error/line -1,
:clojure.error/cause "java.lang.NullPointerException",
:clojure.error/symbol user/eval333$fn,
:clojure.error/phase :execution},
:clojure.main/trace
{:via
[{:type java.util.concurrent.ExecutionException,
:message
"java.lang.NullPointerException: java.lang.NullPointerException",
:at
[datomic.promise$throw_executionexception_if_throwable
invokeStatic
"promise.clj"
10]}
{:type java.lang.NullPointerException,
:message "java.lang.NullPointerException",
:at [user$eval333$fn__334 invoke "NO_SOURCE_FILE" -1]}],
:trace
[[user$eval333$fn__334 invoke "NO_SOURCE_FILE" -1]
[datomic.error$deserialize_exception invokeStatic "error.clj" 157]
[datomic.error$deserialize_exception invoke "error.clj" 139]
[datomic.peer.Connection notify_error "peer.clj" 379]
[datomic.connector$fn__16402 invokeStatic "connector.clj" 155]
[datomic.connector$fn__16402 invoke "connector.clj" 153]
[clojure.lang.MultiFn invoke "MultiFn.java" 234]
[datomic.connector$create_hornet_notifier$fn__16408$fn__16409$fn__16412$fn__16413
invoke
"connector.clj"
180]
[datomic.connector$create_hornet_notifier$fn__16408$fn__16409$fn__16412
invoke
"connector.clj"
175]
[datomic.connector$create_hornet_notifier$fn__16408$fn__16409
invoke
"connector.clj"
173]
[clojure.core$binding_conveyor_fn$fn__5754 invoke "core.clj" 2030]
[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]],
:cause "java.lang.NullPointerException"}}
Log:
2019-12-16 06:18:20.519 INFO default datomic.kv-cluster - {:tid 13, :phase :begin, :etag "5df709af-2904-4c4f-82ba-6f680b769be6", :rev 2, :pod-key "pod-log-tail/skylink-e0312869-65ff-41cf-a9fc-c8730cb7a396", :pid 29399, :event :kv-cluster/update-pod, :tailid "5df709af-2904-4c4f-82ba-6f680b769be6", :bufsize nil}
2019-12-16 06:18:20.523 INFO default datomic.kv-cluster - {:tid 13, :phase :end, :etag "5df709af-2904-4c4f-82ba-6f680b769be6", :rev 2, :pod-key "pod-log-tail/skylink-e0312869-65ff-41cf-a9fc-c8730cb7a396", :pid 29399, :event :kv-cluster/update-pod, :tailid "5df709af-2904-4c4f-82ba-6f680b769be6", :msec 3.5, :bufsize nil}
2019-12-16 06:18:20.526 INFO default datomic.update - {:event :transactor/admin-command, :cmd :start-database, :arg "skylink-e0312869-65ff-41cf-a9fc-c8730cb7a396", :result {:version "0.9.6014", :peers 2, :type :starter, :status :started}, :pid 29399, :tid 32}
2019-12-16 06:18:20.558 WARN default o.a.activemq.artemis.core.server - AMQ222165: No Dead Letter Address configured for queue skylink-e0312869-65ff-41cf-a9fc-c8730cb7a396.tx-submit5df721ac-888e-4047-b8b1-ec246d21b4a8 in AddressSettings
2019-12-16 06:18:20.559 WARN default o.a.activemq.artemis.core.server - AMQ222166: No Expiry Address configured for queue skylink-e0312869-65ff-41cf-a9fc-c8730cb7a396.tx-submit5df721ac-888e-4047-b8b1-ec246d21b4a8 in AddressSettings
2019-12-16 06:18:20.571 INFO default datomic.update - {:task :reader, :event :update/loop, :phase :begin, :pid 29399, :tid 33}
2019-12-16 06:18:21.335 WARN default o.a.activemq.artemis.core.server - AMQ222165: No Dead Letter Address configured for queue skylink-e0312869-65ff-41cf-a9fc-c8730cb7a396.tx-result5df721ad-84b4-4faa-bf3d-4f76dbc44524 in AddressSettings
2019-12-16 06:18:21.335 WARN default o.a.activemq.artemis.core.server - AMQ222166: No Expiry Address configured for queue skylink-e0312869-65ff-41cf-a9fc-c8730cb7a396.tx-result5df721ad-84b4-4faa-bf3d-4f76dbc44524 in AddressSettings
2019-12-16 06:18:21.599 INFO default datomic.log - {:event :log/load-segments, :count 0, :pid 29399, :tid 40}
2019-12-16 06:18:21.664 INFO default datomic.log - {:event :log/catchup, :bytes 149812, :tail-t 1211, :index-t 66, :msec 86, :pid 29399, :tid 11}
2019-12-16 06:18:21.670 INFO default datomic.update - {:task :fressianer, :event :update/loop, :phase :begin, :pid 29399, :tid 43}
2019-12-16 06:18:21.673 INFO default datomic.update - {:task :notifier, :event :update/loop, :phase :begin, :pid 29399, :tid 44}
2019-12-16 06:18:21.686 INFO default datomic.update - {:task :processor, :event :update/loop, :phase :begin, :pid 29399, :tid 45}
2019-12-16 06:18:21.698 INFO default datomic.update - {:task :block-notifier, :event :update/loop, :phase :begin, :pid 29399, :tid 46}
2019-12-16 06:18:21.719 INFO default datomic.update - {:message "Update failed", :pid 29399, :tid 45}
java.lang.NullPointerException: null
at datomic.db$next_valid_inst.invokeStatic(db.clj:3083)
at datomic.db$next_valid_inst.invoke(db.clj:3079)
at datomic.db.ProcessExpander.getData(db.clj:3287)
at datomic.db$with_tx.invokeStatic(db.clj:3360)
at datomic.db$with_tx.invoke(db.clj:3348)
at datomic.update$processor$fn__20352$fn__20353$fn__20354$fn__20358$fn__20361$fn__20362.invoke(update.clj:250)
at clojure.lang.Atom.swap(Atom.java:37)
at clojure.core$swap_BANG_.invokeStatic(core.clj:2352)
at clojure.core$swap_BANG_.invoke(core.clj:2345)
at datomic.update$processor$fn__20352$fn__20353$fn__20354$fn__20358$fn__20361.invoke(update.clj:246)
at datomic.update$processor$fn__20352$fn__20353$fn__20354$fn__20358.invoke(update.clj:244)
at datomic.update$processor$fn__20352$fn__20353$fn__20354.invoke(update.clj:241)
at datomic.update$processor$fn__20352$fn__20353.invoke(update.clj:222)
at datomic.update$processor$fn__20352.invoke(update.clj:222)
at datomic.update$processor.invokeStatic(update.clj:222)
at datomic.update$processor.doInvoke(update.clj:207)
at clojure.lang.RestFn.applyTo(RestFn.java:139)
at clojure.core$apply.invokeStatic(core.clj:667)
at clojure.core$apply.invoke(core.clj:660)
at datomic.update$background$proc__20270.invoke(update.clj:58)
at clojure.lang.AFn.run(AFn.java:22)
at java.lang.Thread.run(Thread.java:748)
2019-12-16 06:18:21.733 INFO default datomic.transaction - {:event :tx/process, :msec 296.0, :txid #uuid "5df721ad-b2b6-4bc2-ba12-fc5ce41c8ed4", :pid 29399, :tid 45}
2019-12-16 06:18:25.496 INFO default datomic.lifecycle - {:tid 16, :username "P2T/AEEwtPafDbYLyvwhCxbJZL/Jhx6cOeORAsMO/ts=", :port 4334, :rev 1180, :host "localhost", :pid 29399, :event :transactor/heartbeat, :version "0.9.6014", :timestamp 1576477105477, :encrypt-channel true}
2019-12-16 06:18:30.481 INFO default datomic.lifecycle - {:tid 16, :username "P2T/AEEwtPafDbYLyvwhCxbJZL/Jhx6cOeORAsMO/ts=", :port 4334, :rev 1181, :host "localhost", :pid 29399, :event :transactor/heartbeat, :version "0.9.6014", :timestamp 1576477110477, :encrypt-channel true}
Tested versions:
Clojure:1.10.1
datomic: 0.9.5981 & 0.9.6014
storage: dynamodb (but happens the same in postgresql after doing a backup/restore)
Java: 8 & 13