Runaway condition causes infinite round-trip

[jocrau]

There is a runaway condition in Datsync. It seems as if transacting the :txInstant is sent to the other side to be transacted which causes a round-trip.

This occurs after I implemented a handler for the key :dat.sync.client.bootstrap/complete?. This caused an error on the client side and stopped the round trip.

Here is an excerpt of the JS log:

core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {:db/current-tx 536871186}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ()
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {:db/current-tx 536871187}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ()
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {:db/current-tx 536871188}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ()
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {:db/current-tx 536871189}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ()
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {:db/current-tx 536871190}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ()
utils.cljs?rel=1479751156161:49 Figwheel: notified of file changes
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {-1001849 1853, :db/current-tx 536871191}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ([-1853 :db/txInstant #inst "2016-12-08T21:20:13.410-00:00" 536871191 true] [-1853 :dat.sync.remote.db/id 13194139537180 536871191 true])
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {-1001850 1854, :db/current-tx 536871192}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ([-1854 :db/txInstant #inst "2016-12-08T21:20:13.446-00:00" 536871192 true] [-1854 :dat.sync.remote.db/id 13194139537181 536871192 true])
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {-1001851 1855, :db/current-tx 536871193}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ([-1855 :db/txInstant #inst "2016-12-08T21:20:13.484-00:00" 536871193 true] [-1855 :dat.sync.remote.db/id 13194139537182 536871193 true])
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {:db/current-tx 536871194}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ()
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {:db/current-tx 536871195}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ()
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:584] - Calling globalize datoms
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:38] - Tx report tempids: {:db/current-tx 536871196}
core.cljs?rel=1479751134668:143 INFO [com.elumindata.optiq.persistence.sync:39] - Sending local tx datoms to server as tx: ()
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.tx/error
core.cljs?rel=1479751134668:143 ERROR [dat.reactor:228] - No definition for event: [:dat.sync.tx/error {:tx.error/message "java.lang.IllegalArgumentException: :db.error/not-an-entity Unable to resolve entity: :dat.sync.remote.db/id", :tx/data ([-1809 :db/txInstant #inst "2016-12-08T21:20:10.752-00:00" 536871059 true] [-1809 :dat.sync.remote.db/id 13194139537136 536871059 true]), :tx/error {:db/error :db.error/not-an-entity}}] You should probably go add one in your events ns
core.cljs?rel=1479751134668:143 DEBUG [dat.remote.impl.sente:85] - Sente message recieved: :chsk/recv
core.cljs?rel=1479751134668:143 INFO [dat.remote.impl.sente:115] - :chsk/recv for event-id: :dat.sync.client/recv-remote-tx
core.cljs?rel=1479751134668:143 INFO [dat.sync.client:708] - Running remote-tx in :dat.sync/recv-remote-tx.
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:394] - Calling translate-eids
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:410] - n local eids w remote 0
core.cljs?rel=1479751134668:143 DEBUG [dat.sync.client:411] - n local eids w/o remote 1
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:192] - Handler :dat.reactor/local-tx called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:187] - Handler :dat.reactor/resolve-tx-report called.
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:127] - Adding effects for effect-ids: (:dat.reactor/execute-tx-report-handlers!)
core.cljs?rel=1479751134668:143 DEBUG [dat.reactor:204] - Effect handler :dat.reactor/fire-tx-report-handlers! called.

[metasoarous]

Sorry @jocrau I haven't forgotten about this, I've just been taking time to think through the next steps on the project. I'll add a temp fix for you for now, but we're starting to make progress on more general solutions for things here.