search

mit-pdos / noria

Fast web applications through dynamic, partially-stateful dataflow
Apache License 2.0
4.98k stars 242 forks source link

Running `basic-recipe` example more than once causes segfault #107

Closed jbcden closed 5 years ago

jbcden commented 5 years ago

First off, I just want to say that this is a really cool project!

When I tried running the basic-recipe example under noria-server it worked the first time:

Oct 09 23:24:14.093 INFO found initial leader
Oct 09 23:24:14.094 INFO leader listening on external address V4(127.0.0.1:6033)
Oct 09 23:24:14.094 DEBG leader's internal listen address: V4(127.0.0.1:64841)
Oct 09 23:24:14.094 WARN Connected to new leader
Oct 09 23:24:14.095 INFO new worker registered from V4(127.0.0.1:64843), which listens on V4(127.0.0.1:64841)
Oct 09 23:24:14.112 DEBG 0 duplicate queries, version: 0
Oct 09 23:24:14.112 INFO starting migration
Oct 09 23:24:14.112 DEBG 4 queries, 2 of which are named, version: 1
Oct 09 23:24:14.112 INFO Schema version advanced from 0 to 1
Oct 09 23:24:14.113 DEBG Assigning primary key (aid) for base Article
Oct 09 23:24:14.113 INFO adding new base, node: 1
Oct 09 23:24:14.114 DEBG registering query "Article"
Oct 09 23:24:14.114 INFO adding new base, node: 2
Oct 09 23:24:14.114 DEBG registering query "Vote"
Oct 09 23:24:14.114 DEBG Making QG for "VoteCount"
Oct 09 23:24:14.115 INFO No reuse opportunity, adding fresh query
Oct 09 23:24:14.115 DEBG Added final MIR node for query named "VoteCount"
Oct 09 23:24:14.116 INFO adding new node, type: internal Distinct node, node: 3
Oct 09 23:24:14.116 INFO adding new node, type: internal |*| γ[0] node, node: 4
Oct 09 23:24:14.116 INFO adding new node, type: internal π[0, 1] node, node: 5
Oct 09 23:24:14.116 DEBG registering query "VoteCount"
Oct 09 23:24:14.117 DEBG Making QG for "ArticleWithVoteCount"
Oct 09 23:24:14.117 INFO No reuse opportunity, adding fresh query
Oct 09 23:24:14.118 DEBG Added final MIR node for query named "ArticleWithVoteCount"
Oct 09 23:24:14.118 INFO adding new node, type: internal [1:0, 1:1, 1:2, 5:1] 1:0 ⋈ 5:0 node, node: 6
Oct 09 23:24:14.119 INFO adding new node, type: internal π[0, 1, 2, 3] node, node: 7
Oct 09 23:24:14.119 DEBG registering query "ArticleWithVoteCount"
Oct 09 23:24:14.119 INFO finalizing migration, #nodes: 7
Oct 09 23:24:14.120 DEBG node added to domain, domain: 0, type: B, node: 1
Oct 09 23:24:14.120 DEBG node added to domain, domain: 0, type: B, node: 2
Oct 09 23:24:14.120 DEBG node added to domain, domain: 0, type: internal Distinct node, node: 3
Oct 09 23:24:14.120 DEBG node added to domain, domain: 0, type: internal |*| γ[0] node, node: 4
Oct 09 23:24:14.120 DEBG node added to domain, domain: 0, type: internal π[0, 1] node, node: 5
Oct 09 23:24:14.121 DEBG node added to domain, domain: 0, type: internal [1:0, 1:1, 1:2, 5:1] 1:0 ⋈ 5:0 node, node: 6
Oct 09 23:24:14.121 DEBG node added to domain, domain: 0, type: internal π[0, 1, 2, 3] node, node: 7
Oct 09 23:24:14.121 DEBG node added to domain, domain: 0, type: reader node, node: 8
Oct 09 23:24:14.121 DEBG assigning local index, local: 0, node: 1, type: B, domain: 0
Oct 09 23:24:14.122 DEBG assigning local index, local: 1, node: 2, type: B, domain: 0
Oct 09 23:24:14.122 DEBG assigning local index, local: 2, node: 3, type: internal Distinct node, domain: 0
Oct 09 23:24:14.122 DEBG assigning local index, local: 3, node: 4, type: internal |*| γ[0] node, domain: 0
Oct 09 23:24:14.123 DEBG assigning local index, local: 4, node: 5, type: internal π[0, 1] node, domain: 0
Oct 09 23:24:14.123 DEBG assigning local index, local: 5, node: 6, type: internal [1:0, 1:1, 1:2, 5:1] 1:0 ⋈ 5:0 node, domain: 0
Oct 09 23:24:14.123 DEBG assigning local index, local: 6, node: 7, type: internal π[0, 1, 2, 3] node, domain: 0
Oct 09 23:24:14.123 DEBG assigning local index, local: 7, node: 8, type: reader node, domain: 0
Oct 09 23:24:14.130 DEBG booting new domains
Oct 09 23:24:14.131 INFO sending domain 0.0 to worker Ok(V4(127.0.0.1:64841))
Oct 09 23:24:14.133 INFO booted domain, nodes: 8, shard: 0, domain: 0
Oct 09 23:24:14.134 DEBG accepted new connection, base: false, id: 0.0
Oct 09 23:24:14.134 DEBG mutating existing domains
Oct 09 23:24:14.134 INFO bringing up inter-domain connections
Oct 09 23:24:14.134 INFO initializing new materializations
Oct 09 23:24:14.134 INFO adding lookup index to view, columns: [0], node: 1
Oct 09 23:24:14.135 INFO adding lookup index to view, columns: [0, 1], node: 3
Oct 09 23:24:14.135 INFO adding lookup index to view, columns: [0], node: 5
Oct 09 23:24:14.135 INFO adding lookup index to view, columns: [0], node: 4
Oct 09 23:24:14.135 INFO adding lookup index to view, columns: [0], node: 2
Oct 09 23:24:14.136 WARN using partial materialization for 8
Oct 09 23:24:14.136 WARN using partial materialization for 4
Oct 09 23:24:14.136 WARN full because required, node: 3
Oct 09 23:24:14.136 INFO adding index to view to enable partial, columns: [0], on: 3
Oct 09 23:24:14.136 WARN full because descendant is full, child: 3, node: 2
Oct 09 23:24:14.137 DEBG new fully-materalized node: B
Oct 09 23:24:14.137 INFO no need to replay empty new base, node: 1
Oct 09 23:24:14.534 DEBG new fully-materalized node: B
Oct 09 23:24:14.534 INFO no need to replay empty new base, node: 2
Oct 09 23:24:14.618 DEBG new fully-materalized node: internal Distinct node
Oct 09 23:24:14.618 INFO beginning reconstruction of internal Distinct node
Oct 09 23:24:14.619 INFO domain replay path is [(DomainIndex(0), [(NodeIndex(2), None), (NodeIndex(3), None)])], tag: 0, node: 3
Oct 09 23:24:14.670 INFO told about terminating replay path [ReplayPathSegment { node: LocalNodeIndex { id: 2 }, partial_key: None }], tag: 0, shard: 0, domain: 0
Oct 09 23:24:14.673 INFO told to prepare full state, key: [0], shard: 0, domain: 0
Oct 09 23:24:14.673 INFO told to prepare full state, key: [0, 1], shard: 0, domain: 0
Oct 09 23:24:14.673 INFO starting replay, shard: 0, domain: 0
Oct 09 23:24:14.733 DEBG current state cloned for replay, μs: 59883, shard: 0, domain: 0
Oct 09 23:24:14.734 DEBG replaying batch, #: 0, shard: 0, domain: 0
Oct 09 23:24:14.734 DEBG last batch processed, terminal: true, shard: 0, domain: 0
Oct 09 23:24:14.734 DEBG last batch received, local: 2, shard: 0, domain: 0
Oct 09 23:24:14.734 DEBG node is fully up-to-date, passes: 1, local: 2, shard: 0, domain: 0
Oct 09 23:24:14.734 INFO acknowledging replay completed, node: 2, shard: 0, domain: 0
Oct 09 23:24:15.038 INFO reconstruction completed, node: 3, ms: 420
Oct 09 23:24:15.038 DEBG new partially-materialized node: internal |*| γ[0] node
Oct 09 23:24:15.038 INFO beginning reconstruction of internal |*| γ[0] node
Oct 09 23:24:15.039 INFO domain replay path is [(DomainIndex(0), [(NodeIndex(3), Some([0])), (NodeIndex(4), Some([0]))])], tag: 1, node: 4
Oct 09 23:24:15.088 INFO told about replay path [ReplayPathSegment { node: LocalNodeIndex { id: 3 }, partial_key: Some([0]) }], tag: 1, shard: 0, domain: 0
Oct 09 23:24:15.090 INFO told to prepare partial state, tags: [Tag(1)], key: [0], shard: 0, domain: 0
Oct 09 23:24:15.147 INFO reconstruction completed, node: 4, ms: 109
Oct 09 23:24:15.148 DEBG new stateless node: internal π[0, 1] node
Oct 09 23:24:15.148 DEBG no need to replay non-materialized view, node: 5
Oct 09 23:24:15.469 INFO reconstruction completed, node: 5, ms: 320
Oct 09 23:24:15.469 DEBG new stateless node: internal [1:0, 1:1, 1:2, 5:1] 1:0 ⋈ 5:0 node
Oct 09 23:24:15.469 DEBG no need to replay non-materialized view, node: 6
Oct 09 23:24:15.513 INFO reconstruction completed, node: 6, ms: 43
Oct 09 23:24:15.513 DEBG new stateless node: internal π[0, 1, 2, 3] node
Oct 09 23:24:15.513 DEBG no need to replay non-materialized view, node: 7
Oct 09 23:24:15.566 INFO reconstruction completed, node: 7, ms: 52
Oct 09 23:24:15.566 DEBG new stateless node: reader node
Oct 09 23:24:15.566 INFO beginning reconstruction of reader node
Oct 09 23:24:15.567 INFO domain replay path is [(DomainIndex(0), [(NodeIndex(1), Some([0])), (NodeIndex(6), Some([0])), (NodeIndex(7), Some([0])), (NodeIndex(8), Some([0]))])], tag: 2, node: 8
Oct 09 23:24:15.620 INFO told about replay path [ReplayPathSegment { node: LocalNodeIndex { id: 5 }, partial_key: Some([0]) }, ReplayPathSegment { node: LocalNodeIndex { id: 6 }, partial_key: Some([0]) }, ReplayPathSegment { node: LocalNodeIndex { id: 7 }, partial_key: Some([0]) }], tag: 2, shard: 0, domain: 0
Oct 09 23:24:15.679 INFO reconstruction completed, node: 8, ms: 112
Oct 09 23:24:15.679 WARN migration completed, ms: 1566
digraph {{
    node [shape=record, fontsize=10]
    n0 [style="filled", fillcolor=white, label="(source)"]
    n1 [style="filled", fillcolor="/set312/1", label="{ { 1 / l0 / Article | B | █ } | aid, \ntitle, \nurl | unsharded }"]
    n2 [style="filled", fillcolor="/set312/1", label="{ { 2 / l1 / Vote | B | █ } | aid, \nuid | unsharded }"]
    n3 [style="filled", fillcolor="/set312/1", label="{{ 3 / l2 / q_f7dd1eab44a4f019_n0_distinct | Distinct | █ } | aid, \nuid | unsharded }"]
    n4 [style="filled", fillcolor="/set312/1", label="{{ 4 / l3 / q_f7dd1eab44a4f019_n0 | \|*\| γ[0] | ░ } | aid, \nvotes | unsharded }"]
    n5 [style="filled", fillcolor="/set312/1", label="{{ 5 / l4 / VoteCount | π[0, 1]  } | aid, \nvotes | unsharded }"]
    n6 [style="filled", fillcolor="/set312/1", label="{{ 6 / l5 / q_3697f743a02ca52_n0 | [1:0, 1:1, 1:2, 5:1] 1:0 ⋈ 5:0  } | aid, \ntitle, \nurl, \nvotes | unsharded }"]
    n7 [style="filled", fillcolor="/set312/1", label="{{ 7 / l6 / q_3697f743a02ca52_n1 | π[0, 1, 2, 3]  } | aid, \ntitle, \nurl, \nvotes | unsharded }"]
    n8 [style="filled", fillcolor="/set312/1", label="{ { 8 / l7 / ArticleWithVoteCount | ░ } | (reader / ⚷: [0]) | unsharded }"]
    n0 -> n1 [ style=invis ]
    n0 -> n2 [ style=invis ]
    n2 -> n3 [  ]
    n3 -> n4 [  ]
    n4 -> n5 [  ]
    n1 -> n6 [  ]
    n5 -> n6 [  ]
    n6 -> n7 [  ]
    n7 -> n8 [  ]
}}
Oct 09 23:24:15.694 DEBG accepted new connection, base: true, id: 0.0
Creating article...
Creating new article...
Casting vote...
Finished writing! Let's wait for things to propagate...
Reading...
Ok(
    [
        [
            Int(1),
            TinyText("test title"),
            Text("http://pdos.csail.mit.edu"),
            BigInt(1)
        ]
    ]
)

However, when I ran it a second time, I got a segfault:

Oct 09 23:24:43.345 INFO found initial leader
Oct 09 23:24:43.348 INFO leader listening on external address V4(127.0.0.1:6033)
Oct 09 23:24:43.348 DEBG leader's internal listen address: V4(127.0.0.1:64865)
Oct 09 23:24:43.349 WARN Connected to new leader
Oct 09 23:24:43.352 INFO new worker registered from V4(127.0.0.1:64867), which listens on V4(127.0.0.1:64865)
Oct 09 23:24:43.491 DEBG 0 duplicate queries, version: 0
Oct 09 23:24:43.492 INFO starting migration
Oct 09 23:24:43.492 DEBG 4 queries, 2 of which are named, version: 1
Oct 09 23:24:43.492 INFO Schema version advanced from 0 to 1
Oct 09 23:24:43.493 DEBG Assigning primary key (aid) for base Article
Oct 09 23:24:43.494 INFO adding new base, node: 1
Oct 09 23:24:43.495 DEBG registering query "Article"
Oct 09 23:24:43.497 INFO adding new base, node: 2
Oct 09 23:24:43.497 DEBG registering query "Vote"
Oct 09 23:24:43.499 DEBG Making QG for "VoteCount"
Oct 09 23:24:43.500 INFO No reuse opportunity, adding fresh query
Oct 09 23:24:43.501 DEBG Added final MIR node for query named "VoteCount"
Oct 09 23:24:43.502 INFO adding new node, type: internal Distinct node, node: 3
Oct 09 23:24:43.503 INFO adding new node, type: internal |*| γ[0] node, node: 4
Oct 09 23:24:43.503 INFO adding new node, type: internal π[0, 1] node, node: 5
Oct 09 23:24:43.504 DEBG registering query "VoteCount"
Oct 09 23:24:43.504 DEBG Making QG for "ArticleWithVoteCount"
Oct 09 23:24:43.505 INFO No reuse opportunity, adding fresh query
Oct 09 23:24:43.505 DEBG Added final MIR node for query named "ArticleWithVoteCount"
Oct 09 23:24:43.506 INFO adding new node, type: internal [1:0, 1:1, 1:2, 5:1] 1:0 ⋈ 5:0 node, node: 6
Oct 09 23:24:43.507 INFO adding new node, type: internal π[0, 1, 2, 3] node, node: 7
Oct 09 23:24:43.507 DEBG registering query "ArticleWithVoteCount"
Oct 09 23:24:43.507 INFO finalizing migration, #nodes: 7
Oct 09 23:24:43.508 DEBG node added to domain, domain: 0, type: B, node: 1
Oct 09 23:24:43.508 DEBG node added to domain, domain: 0, type: B, node: 2
Oct 09 23:24:43.508 DEBG node added to domain, domain: 0, type: internal Distinct node, node: 3
Oct 09 23:24:43.509 DEBG node added to domain, domain: 0, type: internal |*| γ[0] node, node: 4
Oct 09 23:24:43.509 DEBG node added to domain, domain: 0, type: internal π[0, 1] node, node: 5
Oct 09 23:24:43.509 DEBG node added to domain, domain: 0, type: internal [1:0, 1:1, 1:2, 5:1] 1:0 ⋈ 5:0 node, node: 6
Oct 09 23:24:43.510 DEBG node added to domain, domain: 0, type: internal π[0, 1, 2, 3] node, node: 7
Oct 09 23:24:43.511 DEBG node added to domain, domain: 0, type: reader node, node: 8
Oct 09 23:24:43.513 DEBG assigning local index, local: 0, node: 1, type: B, domain: 0
Oct 09 23:24:43.514 DEBG assigning local index, local: 1, node: 2, type: B, domain: 0
Oct 09 23:24:43.515 DEBG assigning local index, local: 2, node: 3, type: internal Distinct node, domain: 0
Oct 09 23:24:43.516 DEBG assigning local index, local: 3, node: 4, type: internal |*| γ[0] node, domain: 0
Oct 09 23:24:43.517 DEBG assigning local index, local: 4, node: 5, type: internal π[0, 1] node, domain: 0
Oct 09 23:24:43.517 DEBG assigning local index, local: 5, node: 6, type: internal [1:0, 1:1, 1:2, 5:1] 1:0 ⋈ 5:0 node, domain: 0
Oct 09 23:24:43.518 DEBG assigning local index, local: 6, node: 7, type: internal π[0, 1, 2, 3] node, domain: 0
Oct 09 23:24:43.519 DEBG assigning local index, local: 7, node: 8, type: reader node, domain: 0
Oct 09 23:24:43.520 DEBG booting new domains
Oct 09 23:24:43.521 INFO sending domain 0.0 to worker Ok(V4(127.0.0.1:64865))
Oct 09 23:24:43.524 INFO booted domain, nodes: 8, shard: 0, domain: 0
Oct 09 23:24:43.525 DEBG accepted new connection, base: false, id: 0.0
Oct 09 23:24:43.525 DEBG mutating existing domains
Oct 09 23:24:43.525 INFO bringing up inter-domain connections
Oct 09 23:24:43.526 INFO initializing new materializations
Oct 09 23:24:43.527 INFO adding lookup index to view, columns: [0], node: 2
Oct 09 23:24:43.529 INFO adding lookup index to view, columns: [0], node: 4
Oct 09 23:24:43.531 INFO adding lookup index to view, columns: [0], node: 5
Oct 09 23:24:43.532 INFO adding lookup index to view, columns: [0, 1], node: 3
Oct 09 23:24:43.533 INFO adding lookup index to view, columns: [0], node: 1
Oct 09 23:24:43.533 WARN using partial materialization for 8
Oct 09 23:24:43.534 WARN using partial materialization for 4
Oct 09 23:24:43.534 WARN full because required, node: 3
Oct 09 23:24:43.534 INFO adding index to view to enable partial, columns: [0], on: 3
Oct 09 23:24:43.535 WARN full because descendant is full, child: 3, node: 2
Oct 09 23:24:43.536 DEBG new fully-materalized node: B
Oct 09 23:24:43.536 INFO no need to replay empty new base, node: 1
Oct 09 23:24:44.108 DEBG new fully-materalized node: B
Oct 09 23:24:44.108 INFO no need to replay empty new base, node: 2
Oct 09 23:24:44.283 DEBG new fully-materalized node: internal Distinct node
Oct 09 23:24:44.283 INFO beginning reconstruction of internal Distinct node
Oct 09 23:24:44.284 INFO domain replay path is [(DomainIndex(0), [(NodeIndex(2), None), (NodeIndex(3), None)])], tag: 0, node: 3
Oct 09 23:24:44.672 INFO told about terminating replay path [ReplayPathSegment { node: LocalNodeIndex { id: 2 }, partial_key: None }], tag: 0, shard: 0, domain: 0
Segmentation fault: 11

I am running on macos High Sierra.

I am not sure if this is an actual issue but wanted to let you all know!

ms705 commented 5 years ago

Thanks for letting us know -- we'll look into it!

We haven't tested Noria much on Mac OS X (we develop on Linux primarily), but this is certainly unexpected.

ekmartin commented 5 years ago

This should be fixed on the latest master now — please give it a try :)

https://github.com/mit-pdos/noria/commit/f7069dc153e11a847941602f019d3d956dac55e8

jonhoo commented 5 years ago

Does this bump the RocksDB version we're using too, or are we still on 5.14.2?

ekmartin commented 5 years ago

@jonhoo: still 5.14.2 — want me to bump it to 5.15.10?

jonhoo commented 5 years ago

Oh, no, that's fine. Just wanted to check if I had to re-compile my local RocksDB build :)

ekmartin commented 5 years ago

👍

jbcden commented 5 years ago

Just wanted to confirm that this is working for me now! Thanks so much for the quick response!