Issues altering Idents in Datomic

gistfile1.md

Follow up from issues raised here: https://groups.google.com/d/msg/datomic/blgLZkYF5xA/LFjGCASHZNUJ

N.B. These experiments were carried out on a restored backup of the DB (so therefore backing up and restoring isn't a viable solution).

Keywords appear to get added to DB values like so:

user=> (.addKeyword db :this-is-a-test 999999999)
datomic.db.Db@d37f7c59
user=> (d/ident *1 999999999)
:this-is-a-test

So what classes call that?...

$ grep -r 'addKeyword' .
Binary file ./db/Db.class matches
Binary file ./db/IDbImpl.class matches
Binary file ./db$key_hook.class matches

datomic.db/key-hook seems interesting and from further inspection it is called on connect to build the DB instance available in the connection's .-db_ref. So let's wrap it and collect the results in order:

(require 'datomic.db)
(def seen (atom []))
(letfn [(key-hook-wrap [_a db d _b]
          (let [orig-hook #'datomic.db/key-hook
                kw        (.getV d)
                new-db    (orig-hook _a db d _b)]
            (when (or (= kw :NEW)
                      (= kw :OLD))
              (swap! seen conj {:datom d :kw kw :eid (.getE d) :new-db new-db}))
            new-db))]
  (alter-var-root #'datomic.db/hooks (constantly (assoc datomic.db/hooks 10 key-hook-wrap)))))
(datomic.api/connect "datomic:free://localhost:4334/prod-clone")

seen atom contains:

user=> (pprint @seen)

[{:datom
  #datom[277076930200571 10 :NEW 13194139642147 true],
  :kw :NEW,
  :eid 277076930200571,
  :new-db datomic.db.Db@71ef4e46}
 {:datom
  #datom[277076930200571 10 :NEW 13194139642146 false],
  :kw :NEW,
  :eid 277076930200571,
  :new-db datomic.db.Db@71ef4e46}
 {:datom
  #datom[277076930200571 10 :NEW 13194139561614 true],
  :kw :NEW,
  :eid 277076930200571,
  :new-db datomic.db.Db@71ef4e46}
 {:datom
  #datom[277076930200571 10 :OLD 13194139642147 false],
  :kw :OLD,
  :eid 277076930200571,
  :new-db datomic.db.Db@7639be8e}
 {:datom
  #datom[277076930200571 10 :OLD 13194139642146 true],
  :kw :OLD,
  :eid 277076930200571,
  :new-db datomic.db.Db@7639be8e}
 {:datom
  #datom[277076930200571 10 :OLD 13194139561614 false],
  :kw :OLD,
  :eid 277076930200571,
  :new-db datomic.db.Db@7639be8e}
 {:datom
  #datom[277076930200571 10 :OLD 13194139534313 true],
  :kw :OLD,
  :eid 277076930200571,
  :new-db datomic.db.Db@7639be8e}
 {:datom
  #datom[277076930200571 10 :NEW 13194139642147 true],
  :kw :NEW,
  :eid 277076930200571,
  :new-db datomic.db.Db@cda57c01}
 {:datom
  #datom[277076930200571 10 :NEW 13194139642146 false],
  :kw :NEW,
  :eid 277076930200571,
  :new-db datomic.db.Db@cda57c01}
 {:datom
  #datom[277076930200571 10 :NEW 13194139561614 true],
  :kw :NEW,
  :eid 277076930200571,
  :new-db datomic.db.Db@cda57c01}
 {:datom
  #datom[277076930200571 10 :OLD 13194139642147 false],
  :kw :OLD,
  :eid 277076930200571,
  :new-db datomic.db.Db@d1efec49}
 {:datom
  #datom[277076930200571 10 :OLD 13194139642146 true],
  :kw :OLD,
  :eid 277076930200571,
  :new-db datomic.db.Db@d1efec49}
 {:datom
  #datom[277076930200571 10 :OLD 13194139561614 false],
  :kw :OLD,
  :eid 277076930200571,
  :new-db datomic.db.Db@d1efec49}
 {:datom
  #datom[277076930200571 10 :OLD 13194139534313 true],
  :kw :OLD,
  :eid 277076930200571,
  :new-db datomic.db.Db@d1efec49}]

Quick test to show the behaviour of datomic.api/ident as it progressed:

user=> (doseq [x @seen] (prn (d/ident (:new-db x) 277076930200571)))
:NEW
:NEW
:NEW
:OLD
:OLD
:OLD
:OLD
:NEW
:NEW
:NEW
:OLD
:OLD
:OLD
:OLD

Note that the transactions are in AEVT in @seen (although some are duplicated for some reason?!). Surely if you reduce the DB through that, you'll get the wrong result. Is it as simple as ensuring these are applied in transaction order?

user=> (def datoms (map :datom @seen))
#'user/datoms
user=> (= (take 7 datoms) (drop 7 datoms)) ;; duplicated
true
user=> (let [seven (take 7 datoms)] (= (sort datomic.db/aevt-cmp seven) seven)) ;; sorted by aevt
true

Looking at them in transaction order, we see the attempted changes to :db/ident being done (as expected). Note that the last 2 transactions were after the bug was spotted originally - they were the fix attempted that I noted in my first email:

user=> (doseq [x (->> (map :datom @seen) (sort-by #(.tx %)))] (prn x))
#datom[277076930200571 10 :OLD 13194139534313 true]
#datom[277076930200571 10 :OLD 13194139534313 true]
#datom[277076930200571 10 :NEW 13194139561614 true]
#datom[277076930200571 10 :OLD 13194139561614 false]
#datom[277076930200571 10 :NEW 13194139561614 true]
#datom[277076930200571 10 :OLD 13194139561614 false]
#datom[277076930200571 10 :NEW 13194139642146 false]
#datom[277076930200571 10 :OLD 13194139642146 true]
#datom[277076930200571 10 :NEW 13194139642146 false]
#datom[277076930200571 10 :OLD 13194139642146 true]
#datom[277076930200571 10 :NEW 13194139642147 true]
#datom[277076930200571 10 :OLD 13194139642147 false]
#datom[277076930200571 10 :NEW 13194139642147 true]
#datom[277076930200571 10 :OLD 13194139642147 false]

Questions

1. Why are things returned in an order such that transaction 13194139534313 ends up winning?
2. How do we get the DB into a 'good' state? Create a new attribute and migrate the data over? i.e. leave entity 277076930200571 as a 'lost-cause'?

It may well have been human error on our side - it only takes one tired programmer to make a stupid mistake. But what mistake could've resulted in this though? We just used 'Renaming an Identity' as a reference.

The concern is that this could happen again!