java.lang.AssertionError: Assert failed: i

[balopat]

Hi,

Every now and then, the execution of knossos after jepsen tests throws the exception below. I copied the history as well. Am I doing something stupid?

Thanks,
Balint

I'm using in the jepsen test the simple cas model:

:model   (model/cas-register 42)
       :checker (checker/compose
                    {:perf   (checker/perf)
                     :linear checker/linearizable})

The exception:

java.util.concurrent.ExecutionException: java.lang.AssertionError: Assert failed: i
 at java.util.concurrent.FutureTask.report (FutureTask.java:122)
    java.util.concurrent.FutureTask.get (FutureTask.java:192)
    clojure.core$deref_future.invoke (core.clj:2186)
    clojure.core$future_call$reify__6736.deref (core.clj:6683)
    clojure.core$deref.invoke (core.clj:2206)
    clojure.core$map$fn__4553.invoke (core.clj:2624)
    clojure.lang.LazySeq.sval (LazySeq.java:40)
    clojure.lang.LazySeq.seq (LazySeq.java:49)
    clojure.lang.Cons.next (Cons.java:39)
    clojure.lang.RT.next (RT.java:674)
    clojure.core/next (core.clj:64)
    clojure.core.protocols/fn (protocols.clj:170)
    clojure.core.protocols$fn__6478$G__6473__6487.invoke (protocols.clj:19)
    clojure.core.protocols$seq_reduce.invoke (protocols.clj:31)
    clojure.core.protocols/fn (protocols.clj:101)
    clojure.core.protocols$fn__6452$G__6447__6465.invoke (protocols.clj:13)
    clojure.core$reduce.invoke (core.clj:6519)
    clojure.core$into.invoke (core.clj:6600)
    jepsen.checker$compose$reify__6600.check (checker.clj:257)
    jepsen.checker$check_safe.invoke (checker.clj:39)
    jepsen.core$run_BANG_$fn__6821.invoke (core.clj:421)
    jepsen.core$run_BANG_.invoke (core.clj:373)
    jepsen.influxdb_test/fn (influxdb_test.clj:13)
    clojure.test$test_var$fn__7670.invoke (test.clj:704)
    clojure.test$test_var.invoke (test.clj:704)
    clojure.test$test_vars$fn__7692$fn__7697.invoke (test.clj:722)
    clojure.test$default_fixture.invoke (test.clj:674)
    clojure.test$test_vars$fn__7692.invoke (test.clj:722)
    clojure.test$default_fixture.invoke (test.clj:674)
    clojure.test$test_vars.invoke (test.clj:718)
    clojure.test$test_all_vars.invoke (test.clj:728)
    clojure.test$test_ns.invoke (test.clj:747)
    clojure.core$map$fn__4553.invoke (core.clj:2624)
    clojure.lang.LazySeq.sval (LazySeq.java:40)
    clojure.lang.LazySeq.seq (LazySeq.java:49)
    clojure.lang.Cons.next (Cons.java:39)
    clojure.lang.RT.boundedLength (RT.java:1735)
    clojure.lang.RestFn.applyTo (RestFn.java:130)
    clojure.core$apply.invoke (core.clj:632)
    clojure.test$run_tests.doInvoke (test.clj:762)
    clojure.lang.RestFn.applyTo (RestFn.java:137)
    clojure.core$apply.invoke (core.clj:630)
    user$eval85$fn__144$fn__175.invoke (form-init3009603524082798247.clj:1)
    user$eval85$fn__144$fn__145.invoke (form-init3009603524082798247.clj:1)
    user$eval85$fn__144.invoke (form-init3009603524082798247.clj:1)
    user$eval85.invoke (form-init3009603524082798247.clj:1)
    clojure.lang.Compiler.eval (Compiler.java:6782)
    clojure.lang.Compiler.eval (Compiler.java:6772)
    clojure.lang.Compiler.load (Compiler.java:7227)
    clojure.lang.Compiler.loadFile (Compiler.java:7165)
    clojure.main$load_script.invoke (main.clj:275)
    clojure.main$init_opt.invoke (main.clj:280)
    clojure.main$initialize.invoke (main.clj:308)
    clojure.main$null_opt.invoke (main.clj:343)
    clojure.main$main.doInvoke (main.clj:421)
    clojure.lang.RestFn.invoke (RestFn.java:421)
    clojure.lang.Var.invoke (Var.java:383)
    clojure.lang.AFn.applyToHelper (AFn.java:156)
    clojure.lang.Var.applyTo (Var.java:700)
    clojure.main.main (main.java:37)
Caused by: java.lang.AssertionError: Assert failed: i
 at knossos.linear.report$time_coords$fn__6396.invoke (report.clj:179)
    clojure.core$map$fn__4553.invoke (core.clj:2624)
    clojure.lang.LazySeq.sval (LazySeq.java:40)
    clojure.lang.LazySeq.seq (LazySeq.java:49)
    clojure.lang.RT.seq (RT.java:507)
    clojure.core/seq (core.clj:137)
    clojure.core.protocols$seq_reduce.invoke (protocols.clj:30)
    clojure.core.protocols/fn (protocols.clj:101)
    clojure.core.protocols$fn__6452$G__6447__6465.invoke (protocols.clj:13)
    clojure.core$reduce.invoke (core.clj:6519)
    clojure.core$into.invoke (core.clj:6600)
    knossos.linear.report$time_coords.invoke (report.clj:185)
    knossos.linear.report$learnings.invoke (report.clj:427)
    knossos.linear.report$render_analysis_BANG_.invoke (report.clj:632)
    jepsen.checker$reify__6560.check (checker.clj:55)
    jepsen.checker$compose$reify__6600$fn__6602.invoke (checker.clj:256)
    clojure.core$pmap$fn__6744$fn__6745.invoke (core.clj:6729)
    clojure.core$binding_conveyor_fn$fn__4444.invoke (core.clj:1916)
    clojure.lang.AFn.call (AFn.java:18)
    java.util.concurrent.FutureTask.run (FutureTask.java:266)
    java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1142)
    java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:617)
    java.lang.Thread.run (Thread.java:745)

history of operations is the following (simple mix of read and write ops):

0   :invoke :read   nil
0   :ok :read   42.0
0   :invoke :read   nil
0   :ok :read   42.0
1   :invoke :read   nil
1   :ok :read   42.0
2   :invoke :read   nil
2   :ok :read   42.0
0   :invoke :read   nil
0   :ok :read   42.0
1   :invoke :write  4.0
1   :ok :write  4.0
0   :invoke :write  4.0
0   :ok :write  4.0
2   :invoke :write  1.0
2   :ok :write  1.0
2   :invoke :write  3.0
2   :ok :write  3.0
0   :invoke :write  1.0
0   :ok :write  1.0
1   :invoke :read   nil
1   :ok :read   1.0
0   :invoke :write  1.0
0   :ok :write  1.0
0   :invoke :read   nil
0   :ok :read   1.0
2   :invoke :write  0.0
2   :ok :write  0.0
2   :invoke :read   nil
0   :invoke :write  3.0
2   :ok :read   0.0
0   :ok :write  3.0
1   :invoke :read   nil
1   :ok :read   3.0
0   :invoke :write  0.0
0   :ok :write  0.0
2   :invoke :write  2.0
2   :ok :write  2.0
1   :invoke :read   nil
1   :ok :read   2.0
0   :invoke :write  4.0
0   :ok :write  4.0
2   :invoke :write  0.0
2   :ok :write  0.0
2   :invoke :write  2.0
2   :ok :write  2.0
1   :invoke :write  4.0
1   :ok :write  4.0
0   :invoke :read   nil
0   :ok :read   4.0
1   :invoke :write  0.0
1   :ok :write  0.0
2   :invoke :read   nil
2   :ok :read   0.0
0   :invoke :read   nil
0   :ok :read   0.0
1   :invoke :write  1.0
1   :ok :write  1.0
2   :invoke :read   nil
2   :ok :read   1.0
0   :invoke :read   nil
0   :ok :read   1.0
1   :invoke :write  0.0
1   :ok :write  0.0
2   :invoke :read   nil
2   :ok :read   0.0
0   :invoke :read   nil
0   :ok :read   0.0
1   :invoke :write  1.0
1   :ok :write  1.0
2   :invoke :read   nil
2   :ok :read   1.0
0   :invoke :write  2.0
0   :ok :write  2.0
1   :invoke :write  3.0
1   :ok :write  3.0
2   :invoke :read   nil
2   :ok :read   3.0

[balopat]

Additional info: almost exclusively there seems to be a runtime error in the client's setup method when this assertion fails, but I'll validate further.

[aphyr]

On 01/05/2016 11:30 AM, Balint Pato wrote:

Hi,

Every now and then, the execution of knossos after jepsen tests throws the
exception below I copied the history as well Am I doing something stupid?

Thanks,
Balint

I'm using in the jepsen test the simple cas model:

|:model (model/cas-register 42) :checker (checker/compose {:perf (checker/perf)
:linear checker/linearizable}) |

Looks like you had an initial value that was nil, but specified in the model the
initial value was 42?

--Kyle

[balopat]

Thanks, Kyle, it was a problem with the initial value, and that's why it's just happening sometime (when the first operation in the history is a read), however, the problem was a casting issue:

analyis: 
{
:valid? false, 
:configs ( 
   { :model #knossos.model.CASRegister{:value 42}, 
    :pending [{:process 0, :type :invoke, :f :read, :value 42.0, :index 0}]}), 
    :final-paths #{
                    [
                        {:op nil, :model #knossos.model.CASRegister{:value 42}} 
                        {:op {:process 0, :type :ok, :f :read, :value 42.0, :index 1}, :model #knossos.model.Inconsistent{:msg can't read 42.0 from register 42}}]}, 
     :previous-ok nil, 
     :op {:process 0, :type :ok, :f :read, :value 42.0, :index 1}
} 

This assertion error always going to come up for invalid analyses failing on the very first operation as in the final-path "All paths start with the previous completion operation" which is nil in this case.

[aphyr]

Ohhhh hang on, haha, there's another closely related error in knossos.model.memo where precomputed states don't cover reachable states, but that's not the error you hit. Yeah, I agree, we should, um, do something sensible here.

[gaodq]

Hi, Kyle, do you have any efforts on this problem? I have encountered java.lang.AssertionError: Assert failed several times, then the result Valid? is unknow, making me confused.

[aphyr]

@gaodq There are a lot of assertions in Knossos, and without the actual error message and trace it's hard for me to say. I've made some improvements to error handling in the latest knossos release, which went out yesterday, but I can't tell you whether that will cover your problem or not.