Challenge #1: failure running "maelstrom test"

dharmit · March 18, 2023, 3:50am

I’m on Fedora 37 and have openjdk, graphviz and gnuplot installed on my box.

The maelstrom test command fails for me. Below is the jespen.log for the same. Can someone point me what’s going wrong here?

2023-03-18 09:17:36,758{GMT}	INFO	[jepsen test runner] jepsen.core: Command line:
lein run test -w echo --bin /home/dshah/go/bin/maelstrom-echo --node-count 1 --time-limit 10
2023-03-18 09:17:36,808{GMT}	INFO	[jepsen test runner] jepsen.core: Running test:
{:args []
 :remote
 #jepsen.control.retry.Remote{:remote #jepsen.control.scp.Remote{:cmd-remote #jepsen.control.sshj.SSHJRemote{:concurrency-limit 6,
                                                                                                             :conn-spec nil,
                                                                                                             :client nil,
                                                                                                             :semaphore nil},
                                                                 :conn-spec nil},
                              :conn nil}
 :log-net-send false
 :node-count 1
 :availability nil
 :max-txn-length 4
 :concurrency 1
 :db
 #object[maelstrom.db$db$reify__16142
         "0x7d3a9061"
         "maelstrom.db$db$reify__16142@7d3a9061"]
 :max-writes-per-key 16
 :leave-db-running? false
 :name "echo"
 :logging-json? false
 :start-time
 #object[org.joda.time.DateTime "0x307ca947" "2023-03-18T09:17:36.743+05:30"]
 :nemesis-interval 10
 :net
 #object[maelstrom.net$jepsen_net$reify__15251
         "0x61d1315b"
         "maelstrom.net$jepsen_net$reify__15251@61d1315b"]
 :client
 #object[maelstrom.workload.echo$client$reify__16863
         "0x49d5b651"
         "maelstrom.workload.echo$client$reify__16863@49d5b651"]
 :barrier
 #object[java.util.concurrent.CyclicBarrier
         "0x34989ceb"
         "java.util.concurrent.CyclicBarrier@34989ceb"]
 :log-stderr false
 :pure-generators true
 :ssh {:dummy? true}
 :rate 5
 :checker
 #object[jepsen.checker$compose$reify__11881
         "0x61fb3dae"
         "jepsen.checker$compose$reify__11881@61fb3dae"]
 :argv
 ("test"
  "-w"
  "echo"
  "--bin"
  "/home/dshah/go/bin/maelstrom-echo"
  "--node-count"
  "1"
  "--time-limit"
  "10")
 :nemesis
 (jepsen.nemesis.ReflCompose
  {:fm {:start-partition 0,
        :stop-partition 0,
        :kill 1,
        :start 1,
        :pause 1,
        :resume 1},
   :nemeses [#unprintable "jepsen.nemesis.combined$partition_nemesis$reify__16416@9c88323"
             #unprintable "jepsen.nemesis.combined$db_nemesis$reify__16397@6d4bdb75"]})
 :nodes ["n0"]
 :test-count 1
 :latency {:mean 0, :dist :constant}
 :bin "/home/dshah/go/bin/maelstrom-echo"
 :generator
 (jepsen.generator.TimeLimit
  {:limit 10000000000,
   :cutoff nil,
   :gen (jepsen.generator.Any
         {:gens [(jepsen.generator.OnThreads
                  {:f #{:nemesis},
                   :context-filter #object[jepsen.generator.context$make_thread_filter$lazy_filter__9167
                                           "0x453ca7f"
                                           "jepsen.generator.context$make_thread_filter$lazy_filter__9167@453ca7f"],
                   :gen nil})
                 (jepsen.generator.OnThreads
                  {:f #jepsen.generator.context.AllBut{:element :nemesis},
                   :context-filter #object[jepsen.generator.context$make_thread_filter$lazy_filter__9167
                                           "0x5d41b929"
                                           "jepsen.generator.context$make_thread_filter$lazy_filter__9167@5d41b929"],
                   :gen (jepsen.generator.Stagger
                         {:dt 400000000,
                          :next-time nil,
                          :gen (jepsen.generator.EachThread
                                {:fresh-gen #object[maelstrom.workload.echo$workload$fn__16882
                                                    "0x6dd0e2f4"
                                                    "maelstrom.workload.echo$workload$fn__16882@6dd0e2f4"],
                                 :context-filters #object[clojure.core$promise$reify__8591
                                                          "0x333813e7"
                                                          {:status :pending,
                                                           :val nil}],
                                 :gens {}})})})]})})
 :log-net-recv false
 :os
 #object[maelstrom.net$jepsen_os$reify__15254
         "0x292237cd"
         "maelstrom.net$jepsen_os$reify__15254@292237cd"]
 :time-limit 10
 :workload :echo
 :consistency-models [:strict-serializable]
 :topology :grid}

2023-03-18 09:17:38,152{GMT}	INFO	[jepsen node n0] maelstrom.net: Starting Maelstrom network
2023-03-18 09:17:38,153{GMT}	INFO	[jepsen test runner] jepsen.db: Tearing down DB
2023-03-18 09:17:38,154{GMT}	INFO	[jepsen test runner] jepsen.db: Setting up DB
2023-03-18 09:17:38,155{GMT}	INFO	[jepsen node n0] maelstrom.service: Starting services: (lin-kv lin-tso lww-kv seq-kv)
2023-03-18 09:17:38,156{GMT}	INFO	[jepsen node n0] maelstrom.db: Setting up n0
2023-03-18 09:17:38,156{GMT}	INFO	[jepsen node n0] maelstrom.process: launching /home/dshah/go/bin/maelstrom-echo []
2023-03-18 09:17:48,162{GMT}	INFO	[jepsen node n0] maelstrom.db: Tearing down n0
2023-03-18 09:17:49,164{GMT}	INFO	[jepsen node n0] maelstrom.net: Shutting down Maelstrom network
2023-03-18 09:17:49,167{GMT}	WARN	[jepsen test runner] jepsen.core: Test crashed!
clojure.lang.ExceptionInfo: Node n0 crashed with exit status 0. Before crashing, it wrote to STDOUT:



And to STDERR:



Full STDERR logs are available in /home/dshah/src/maelstrom-echo/store/echo/20230318T091736.743+0530/node-logs/n0.log
	at slingshot.support$stack_trace.invoke(support.clj:201)
	at maelstrom.process$stop_node_BANG_.invokeStatic(process.clj:239)
	at maelstrom.process$stop_node_BANG_.invoke(process.clj:217)
	at maelstrom.db$db$reify__16142.teardown_BANG_(db.clj:75)
	at jepsen.db$fn__8744$G__8725__8748.invoke(db.clj:12)
	at jepsen.db$fn__8744$G__8724__8753.invoke(db.clj:12)
	at clojure.core$partial$fn__5908.invoke(core.clj:2642)
	at jepsen.control$on_nodes$fn__8599.invoke(control.clj:314)
	at clojure.lang.AFn.applyToHelper(AFn.java:154)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:667)
	at clojure.core$with_bindings_STAR_.invokeStatic(core.clj:1990)
	at clojure.core$with_bindings_STAR_.doInvoke(core.clj:1990)
	at clojure.lang.RestFn.applyTo(RestFn.java:142)
	at clojure.core$apply.invokeStatic(core.clj:671)
	at clojure.core$bound_fn_STAR_$fn__5818.doInvoke(core.clj:2020)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at dom_top.core$real_pmap_helper$build_thread__211$fn__212.invoke(core.clj:163)
	at clojure.lang.AFn.applyToHelper(AFn.java:152)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:667)
	at clojure.core$with_bindings_STAR_.invokeStatic(core.clj:1990)
	at clojure.core$with_bindings_STAR_.doInvoke(core.clj:1990)
	at clojure.lang.RestFn.invoke(RestFn.java:425)
	at clojure.lang.AFn.applyToHelper(AFn.java:156)
	at clojure.lang.RestFn.applyTo(RestFn.java:132)
	at clojure.core$apply.invokeStatic(core.clj:671)
	at clojure.core$bound_fn_STAR_$fn__5818.doInvoke(core.clj:2020)
	at clojure.lang.RestFn.invoke(RestFn.java:397)
	at clojure.lang.AFn.run(AFn.java:22)
	at java.base/java.lang.Thread.run(Thread.java:833)

johnkoepi · March 21, 2023, 11:19am

Your code crashed (n0 node). See store/echo/20230318T091736.743+0530/node-logs/n0.log for the stacktrace if it was printed out to the stderr.

dharmit · March 21, 2023, 11:49am

There’s nothing in that file. The jespen.log I have shared above is the only log/stack I see.

benbjohnson · March 21, 2023, 4:43pm

Hmm, that seems odd that there aren’t any other files under ./store. Can you provide the code you’re running and some commands to reproduce the issue?

dharmit · March 22, 2023, 12:09pm

that seems odd that there aren’t any other files under ./store

Um, that’s not what I meant. @johnkoepi asked about the contents of n0.log file, to which I said it’s empty.

Here’s the code:

package main

import (
	"encoding/json"
	maelstrom "github.com/jepsen-io/maelstrom/demo/go"
)

func main() {
	n := maelstrom.NewNode()
	n.Handle("echo", func(msg maelstrom.Message) error {
		// Unmarshal the message body
		var body map[string]any
		if err := json.Unmarshal(msg.Body, &body); err != nil {
			return err
		}

		// update the message type to return
		body["type"] = "echo_ok"

		// echo the original message with updated message type
		return n.Reply(msg, body)
	})
}

And here are the commands I ran:

$ go install .

$ ls -l ~/go/bin/maelstrom-echo
-rwxr-xr-x. 1 dshah dshah 2405531 Mar 22 17:35 /home/dshah/go/bin/maelstrom-echo

$ maelstrom test -w echo --bin ~/go/bin/maelstrom-echo --node-count 1 --time-limit 10
WARNING: abs already refers to: #'clojure.core/abs in namespace: clojure.core.matrix.impl.mathsops, being replaced by: #'clojure.core.matrix.impl.mathsops/abs
Warning: protocol #'clojure.core.matrix.protocols/PMathsFunctions is overwriting function abs
WARNING: abs already refers to: #'clojure.core/abs in namespace: clojure.core.matrix.protocols, being replaced by: #'clojure.core.matrix.protocols/abs
WARNING: abs already refers to: #'clojure.core/abs in namespace: clojure.core.matrix, being replaced by: #'clojure.core.matrix/abs
WARNING: abs already refers to: #'clojure.core/abs in namespace: clojure.core.matrix.dataset, being replaced by: #'clojure.core.matrix/abs
WARNING: abs already refers to: #'clojure.core/abs in namespace: incanter.core, being replaced by: #'incanter.core/abs
INFO [2023-03-22 17:36:26,110] main - jepsen.cli Test options:
 {:args [],
 :log-net-send false,
 :node-count 1,
 :availability nil,
 :max-txn-length 4,
 :concurrency 1,
 :max-writes-per-key 16,
 :leave-db-running? false,
 :logging-json? false,
 :nemesis-interval 10,
 :log-stderr false,
 :ssh
 {:dummy? false,
  :username "root",
  :password "root",
  :strict-host-key-checking false,
  :private-key-path nil},
 :rate 5,
 :argv
 ("test"
  "-w"
  "echo"
  "--bin"
  "/home/dshah/go/bin/maelstrom-echo"
  "--node-count"
  "1"
  "--time-limit"
  "10"),
 :nemesis #{},
 :nodes ["n0"],
 :test-count 1,
 :latency {:mean 0, :dist :constant},
 :bin "/home/dshah/go/bin/maelstrom-echo",
 :log-net-recv false,
 :time-limit 10,
 :workload :echo,
 :consistency-models [:strict-serializable],
 :topology :grid}

INFO [2023-03-22 17:36:26,135] jepsen test runner - jepsen.core Command line:
lein run test -w echo --bin /home/dshah/go/bin/maelstrom-echo --node-count 1 --time-limit 10
INFO [2023-03-22 17:36:26,192] jepsen test runner - jepsen.core Running test:
{:args []
 :remote
 #jepsen.control.retry.Remote{:remote #jepsen.control.scp.Remote{:cmd-remote #jepsen.control.sshj.SSHJRemote{:concurrency-limit 6,
                                                                                                             :conn-spec nil,
                                                                                                             :client nil,
                                                                                                             :semaphore nil},
                                                                 :conn-spec nil},
                              :conn nil}
 :log-net-send false
 :node-count 1
 :availability nil
 :max-txn-length 4
 :concurrency 1
 :db
 #object[maelstrom.db$db$reify__16142
         "0x7d3a9061"
         "maelstrom.db$db$reify__16142@7d3a9061"]
 :max-writes-per-key 16
 :leave-db-running? false
 :name "echo"
 :logging-json? false
 :start-time
 #object[org.joda.time.DateTime "0x307ca947" "2023-03-22T17:36:26.120+05:30"]
 :nemesis-interval 10
 :net
 #object[maelstrom.net$jepsen_net$reify__15251
         "0x61d1315b"
         "maelstrom.net$jepsen_net$reify__15251@61d1315b"]
 :client
 #object[maelstrom.workload.echo$client$reify__16863
         "0x49d5b651"
         "maelstrom.workload.echo$client$reify__16863@49d5b651"]
 :barrier
 #object[java.util.concurrent.CyclicBarrier
         "0x34989ceb"
         "java.util.concurrent.CyclicBarrier@34989ceb"]
 :log-stderr false
 :pure-generators true
 :ssh {:dummy? true}
 :rate 5
 :checker
 #object[jepsen.checker$compose$reify__11881
         "0x61fb3dae"
         "jepsen.checker$compose$reify__11881@61fb3dae"]
 :argv
 ("test"
  "-w"
  "echo"
  "--bin"
  "/home/dshah/go/bin/maelstrom-echo"
  "--node-count"
  "1"
  "--time-limit"
  "10")
 :nemesis
 (jepsen.nemesis.ReflCompose
  {:fm {:start-partition 0,
        :stop-partition 0,
        :kill 1,
        :start 1,
        :pause 1,
        :resume 1},
   :nemeses [#unprintable "jepsen.nemesis.combined$partition_nemesis$reify__16416@9c88323"
             #unprintable "jepsen.nemesis.combined$db_nemesis$reify__16397@6d4bdb75"]})
 :nodes ["n0"]
 :test-count 1
 :latency {:mean 0, :dist :constant}
 :bin "/home/dshah/go/bin/maelstrom-echo"
 :generator
 (jepsen.generator.TimeLimit
  {:limit 10000000000,
   :cutoff nil,
   :gen (jepsen.generator.Any
         {:gens [(jepsen.generator.OnThreads
                  {:f #{:nemesis},
                   :context-filter #object[jepsen.generator.context$make_thread_filter$lazy_filter__9167
                                           "0x453ca7f"
                                           "jepsen.generator.context$make_thread_filter$lazy_filter__9167@453ca7f"],
                   :gen nil})
                 (jepsen.generator.OnThreads
                  {:f #jepsen.generator.context.AllBut{:element :nemesis},
                   :context-filter #object[jepsen.generator.context$make_thread_filter$lazy_filter__9167
                                           "0x5d41b929"
                                           "jepsen.generator.context$make_thread_filter$lazy_filter__9167@5d41b929"],
                   :gen (jepsen.generator.Stagger
                         {:dt 400000000,
                          :next-time nil,
                          :gen (jepsen.generator.EachThread
                                {:fresh-gen #object[maelstrom.workload.echo$workload$fn__16882
                                                    "0x6dd0e2f4"
                                                    "maelstrom.workload.echo$workload$fn__16882@6dd0e2f4"],
                                 :context-filters #object[clojure.core$promise$reify__8591
                                                          "0x333813e7"
                                                          {:status :pending,
                                                           :val nil}],
                                 :gens {}})})})]})})
 :log-net-recv false
 :os
 #object[maelstrom.net$jepsen_os$reify__15254
         "0x292237cd"
         "maelstrom.net$jepsen_os$reify__15254@292237cd"]
 :time-limit 10
 :workload :echo
 :consistency-models [:strict-serializable]
 :topology :grid}

INFO [2023-03-22 17:36:27,567] jepsen node n0 - maelstrom.net Starting Maelstrom network
INFO [2023-03-22 17:36:27,567] jepsen test runner - jepsen.db Tearing down DB
INFO [2023-03-22 17:36:27,568] jepsen test runner - jepsen.db Setting up DB
INFO [2023-03-22 17:36:27,570] jepsen node n0 - maelstrom.service Starting services: (lin-kv lin-tso lww-kv seq-kv)
INFO [2023-03-22 17:36:27,570] jepsen node n0 - maelstrom.db Setting up n0
INFO [2023-03-22 17:36:27,571] jepsen node n0 - maelstrom.process launching /home/dshah/go/bin/maelstrom-echo []
INFO [2023-03-22 17:36:37,577] jepsen node n0 - maelstrom.db Tearing down n0
INFO [2023-03-22 17:36:38,579] jepsen node n0 - maelstrom.net Shutting down Maelstrom network
WARN [2023-03-22 17:36:38,581] jepsen test runner - jepsen.core Test crashed!
clojure.lang.ExceptionInfo: Node n0 crashed with exit status 0. Before crashing, it wrote to STDOUT:



And to STDERR:



Full STDERR logs are available in /home/dshah/src/maelstrom-echo/store/echo/20230322T173626.120+0530/node-logs/n0.log
	at slingshot.support$stack_trace.invoke(support.clj:201)
	at maelstrom.process$stop_node_BANG_.invokeStatic(process.clj:239)
	at maelstrom.process$stop_node_BANG_.invoke(process.clj:217)
	at maelstrom.db$db$reify__16142.teardown_BANG_(db.clj:75)
	at jepsen.db$fn__8744$G__8725__8748.invoke(db.clj:12)
	at jepsen.db$fn__8744$G__8724__8753.invoke(db.clj:12)
	at clojure.core$partial$fn__5908.invoke(core.clj:2642)
	at jepsen.control$on_nodes$fn__8599.invoke(control.clj:314)
	at clojure.lang.AFn.applyToHelper(AFn.java:154)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:667)
	at clojure.core$with_bindings_STAR_.invokeStatic(core.clj:1990)
	at clojure.core$with_bindings_STAR_.doInvoke(core.clj:1990)
	at clojure.lang.RestFn.applyTo(RestFn.java:142)
	at clojure.core$apply.invokeStatic(core.clj:671)
	at clojure.core$bound_fn_STAR_$fn__5818.doInvoke(core.clj:2020)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at dom_top.core$real_pmap_helper$build_thread__211$fn__212.invoke(core.clj:163)
	at clojure.lang.AFn.applyToHelper(AFn.java:152)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:667)
	at clojure.core$with_bindings_STAR_.invokeStatic(core.clj:1990)
	at clojure.core$with_bindings_STAR_.doInvoke(core.clj:1990)
	at clojure.lang.RestFn.invoke(RestFn.java:425)
	at clojure.lang.AFn.applyToHelper(AFn.java:156)
	at clojure.lang.RestFn.applyTo(RestFn.java:132)
	at clojure.core$apply.invokeStatic(core.clj:671)
	at clojure.core$bound_fn_STAR_$fn__5818.doInvoke(core.clj:2020)
	at clojure.lang.RestFn.invoke(RestFn.java:397)
	at clojure.lang.AFn.run(AFn.java:22)
	at java.base/java.lang.Thread.run(Thread.java:833)
ERROR [2023-03-22 17:36:38,586] main - jepsen.cli Oh jeez, I'm sorry, Jepsen broke. Here's why:
clojure.lang.ExceptionInfo: Node n0 crashed with exit status 0. Before crashing, it wrote to STDOUT:



And to STDERR:



Full STDERR logs are available in /home/dshah/src/maelstrom-echo/store/echo/20230322T173626.120+0530/node-logs/n0.log
	at slingshot.support$stack_trace.invoke(support.clj:201)
	at maelstrom.process$stop_node_BANG_.invokeStatic(process.clj:239)
	at maelstrom.process$stop_node_BANG_.invoke(process.clj:217)
	at maelstrom.db$db$reify__16142.teardown_BANG_(db.clj:75)
	at jepsen.db$fn__8744$G__8725__8748.invoke(db.clj:12)
	at jepsen.db$fn__8744$G__8724__8753.invoke(db.clj:12)
	at clojure.core$partial$fn__5908.invoke(core.clj:2642)
	at jepsen.control$on_nodes$fn__8599.invoke(control.clj:314)
	at clojure.lang.AFn.applyToHelper(AFn.java:154)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:667)
	at clojure.core$with_bindings_STAR_.invokeStatic(core.clj:1990)
	at clojure.core$with_bindings_STAR_.doInvoke(core.clj:1990)
	at clojure.lang.RestFn.applyTo(RestFn.java:142)
	at clojure.core$apply.invokeStatic(core.clj:671)
	at clojure.core$bound_fn_STAR_$fn__5818.doInvoke(core.clj:2020)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at dom_top.core$real_pmap_helper$build_thread__211$fn__212.invoke(core.clj:163)
	at clojure.lang.AFn.applyToHelper(AFn.java:152)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:667)
	at clojure.core$with_bindings_STAR_.invokeStatic(core.clj:1990)
	at clojure.core$with_bindings_STAR_.doInvoke(core.clj:1990)
	at clojure.lang.RestFn.invoke(RestFn.java:425)
	at clojure.lang.AFn.applyToHelper(AFn.java:156)
	at clojure.lang.RestFn.applyTo(RestFn.java:132)
	at clojure.core$apply.invokeStatic(core.clj:671)
	at clojure.core$bound_fn_STAR_$fn__5818.doInvoke(core.clj:2020)
	at clojure.lang.RestFn.invoke(RestFn.java:397)
	at clojure.lang.AFn.run(AFn.java:22)
	at java.base/java.lang.Thread.run(Thread.java:833)

$ cat /home/dshah/src/maelstrom-echo/store/echo/20230322T173626.120+0530/node-logs/n0.log

$ ls -lh /home/dshah/src/maelstrom-echo/store/echo/20230322T173626.120+0530/node-logs/n0.log
-rw-r--r--. 1 dshah dshah 0 Mar 22 17:36 /home/dshah/src/maelstrom-echo/store/echo/20230322T173626.120+0530/node-logs/n0.log

johnkoepi · March 22, 2023, 4:39pm

It looks like you forgot to add n.Run(). @dharmit

if err := n.Run(); err != nil {
    log.Fatal(err)
}

To start node life cycle.

dharmit · March 23, 2023, 3:40pm

When requesting help on any online forum, I always fear that the solution to my problem isn’t something silly that I missed/forgot/overlook, like I did this time.

Thank you, @johnkoepi and @benbjohnson, for your help.

system · March 30, 2023, 3:40pm

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.

Topic		Replies	Views
Client read timeout Questions / Help dist-sys-challenge	1	176	December 18, 2023
Unexpected Maelstrome error for maelstrom-unique-ids challenge Questions / Help dist-sys-challenge	2	842	February 23, 2023
First steps with nodejs tutorial Questions / Help docs	7	833	April 14, 2022
Unable to deploy / scale occasionally... Build debugging	10	524	February 17, 2022
Fly launch is failing	2	208	November 23, 2023

Challenge #1: failure running "maelstrom test"

Related Topics