Re: Potential G2-item cycles under serializable isolation

Naw, that's ok. :homebrew-upsert-failed is just letting you know that we
couldn't do the update-insert-update dance. Shouldn't be any safety impact.
:-)

--Kyle

On Thu, Jun 4, 2020, 18:47 Peter Geoghegan <pg(at)bowt(dot)ie> wrote:

> On Thu, Jun 4, 2020 at 3:11 PM Kyle Kingsbury <aphyr(at)jepsen(dot)io> wrote:
> > Give Jepsen a138843d a shot!
>
> Giving it a go now. I'll respond to the rest of your points separately.
>
> FYI, at commit a138843d of Jepsen I can get runs that report roughly
> the same G2-item anomaly at the end, but show a warning that flies by
> -- not sure if this is new or not:
>
> NFO [2020-06-04 15:39:46,204] jepsen worker 5 - jepsen.stolon.append
> not in transaction
> INFO [2020-06-04 15:39:46,204] jepsen worker 12 - jepsen.util 62
> :invoke :txn [[:r 5184 nil] [:r 5184 nil] [:append 5184 4]]
> INFO [2020-06-04 15:39:46,204] jepsen worker 3 - jepsen.stolon.append
> txn insert failed: ERROR: duplicate key value violates unique
> constraint "txn0_pkey"
> Detail: Key (id)=(5184) already exists.
> INFO [2020-06-04 15:39:46,205] jepsen worker 5 - jepsen.stolon.append
> nil insert failed: ERROR: duplicate key value violates unique
> constraint "txn0_pkey"
> Detail: Key (id)=(5184) already exists.
> INFO [2020-06-04 15:39:46,205] jepsen worker 3 - jepsen.stolon.append
> :update #:next.jdbc{:update-count 0}
> INFO [2020-06-04 15:39:46,206] jepsen worker 5 - jepsen.stolon.append
> :update #:next.jdbc{:update-count 1}
> INFO [2020-06-04 15:39:46,206] jepsen worker 5 - jepsen.util 205 :ok
> :txn [[:append 5184 3]]
> WARN [2020-06-04 15:39:46,206] jepsen worker 3 - jepsen.stolon.append
> Caught ex-info
> clojure.lang.ExceptionInfo: throw+: {:type
> :jepsen.stolon.append/homebrew-upsert-failed, :key 5184, :element 1}
> at slingshot.support$stack_trace.invoke(support.clj:201)
> at jepsen.stolon.append$mop_BANG_.invokeStatic(append.clj:111)
> at jepsen.stolon.append$mop_BANG_.invoke(append.clj:80)
> at clojure.core$partial$fn__5828.invoke(core.clj:2638)
> at clojure.core$mapv$fn__8430.invoke(core.clj:6912)
> at clojure.lang.PersistentVector.reduce(PersistentVector.java:343)
> at clojure.core$reduce.invokeStatic(core.clj:6827)
> at clojure.core$mapv.invokeStatic(core.clj:6903)
> at clojure.core$mapv.invoke(core.clj:6903)
> at jepsen.stolon.append.Client$fn__1987.invoke(append.clj:173)
> at next.jdbc.transaction$transact_STAR_.invokeStatic(transaction.clj:39)
> at next.jdbc.transaction$transact_STAR_.invoke(transaction.clj:18)
> at next.jdbc.transaction$eval1805$fn__1806.invoke(transaction.clj:86)
> at
> next.jdbc.protocols$eval1057$fn__1058$G__1048__1067.invoke(protocols.clj:57)
> at next.jdbc$transact.invokeStatic(jdbc.clj:253)
> at next.jdbc$transact.invoke(jdbc.clj:245)
> at jepsen.stolon.append.Client.invoke_BANG_(append.clj:171)
> at jepsen.client.Validate.invoke_BANG_(client.clj:66)
> at
> jepsen.generator.interpreter.ClientWorker.invoke_BANG_(interpreter.clj:61)
> at
> jepsen.generator.interpreter$spawn_worker$fn__9378$fn__9379.invoke(interpreter.clj:136)
> at
> jepsen.generator.interpreter$spawn_worker$fn__9378.invoke(interpreter.clj:119)
> at clojure.core$binding_conveyor_fn$fn__5739.invoke(core.clj:2030)
> at clojure.lang.AFn.call(AFn.java:18)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> at java.base/java.lang.Thread.run(Thread.java:834)
> INFO [2020-06-04 15:39:46,207] jepsen worker 3 - jepsen.util 3 :info
> :txn [[:r 5182 nil] [:r 5184 nil] [:append 5184 1] [:r 5182 nil]]
> [:ex-info "throw+: {:type
> :jepsen.stolon.append/homebrew-upsert-failed, :key 5184, :element 1}"]
> INFO [2020-06-04 15:39:46,207] jepsen worker 12 - jepsen.util 62 :fail
> :txn [[:r 5184 nil] [:r 5184 nil] [:append 5184 4]]
> [:could-not-serialize "ERROR: could not serialize access due to
> concurrent update"]
> INFO [2020-06-04 15:39:46,208] jepsen worker 0 - jepsen.util 50
> :invoke :txn [[:r 5185 nil]]
>
> Is this expected? Does this matter?
>
> --
> Peter Geoghegan
>