Re: E updated with new Causeway
Thomas Leonard <[email protected]>
| Newsgroups | gmane.comp.lang.e.general |
|---|---|
| Message-ID | <[email protected]> |
OK, I spent a couple of days looking at getting E to log in the new
Causeway format. I've got it more-or-less working now, though the code
is very hacky. It's on my "causeway" branch:
http://gitorious.org/repo-roscidus/e-core/commits/causeway
It seems to be tracing things well now (including captp calls and
joins for when blocks).
I was a bit confused by the "message" and "condition" elements in the
SentIf message. It seems that the message doesn't correspond to any
"real" message - it's just a virtual message from the when to its
final resolution, correct? I don't understand what the separate
"condition" is for, or why I need separate "Got" and "Fulfilled"
events. Maybe I'm using this wrong?
E already had lots of causality tracing code (since it was working
before the format changed, as I understand it). But I seem to have had
to implement things differently, which is odd.
I originally had the PendingEvent base class log everything, but that
generated lots of irrelevant events from VatTP (DataCommThunks being
processed). So I moved the logging to the PendingDelivery subclass,
which seems to work better.
E likes to schedule things for a later turn a lot, which makes the
traces a bit noisy. Also, E always sends a __whenMoreResolved on the
result of every message, even if it doesn't care about the result. I
hacked CallExpr to turn "send" into "sendOnly" in some cases.
I'm now wondering how to simplify the traces. For example, take this
simple test-case:
def handler := <unsafe:org.erights.e.elib.debug.makeCausalityLogHandler>(<file:causality.log>.textWriter())
def causalityLogger :=
<unsafe:java.util.logging.makeLogger>.getLogger("e.causality")
causalityLogger.addHandler(handler)
introducer.onTheAir()
var seedVat := <elang:interp.seedVatAuthor>(<unsafe>).virtualize(introducer)
def [remote, _] := seedVat("def remote { to increment(x) { return x + 1 } }")
def runTest() {
interp.blockAtTop()
when (remote) -> {
# Turn on causality tracing.
def tcr := <unsafe:org.erights.e.develop.trace.makeTraceController>
tcr.setProperty("TraceLog_causality", "debug")
when (def result := remote<-increment(5)) -> {
# Stop tracing
tcr.setProperty("TraceLog_causality", "warning")
interp.continueAtTop()
}
}
}
runTest()
The start vat calls "remote.increment(5)" and gets back the answer
(6). The trace (attached) shows 11 turns:
1. [start] sends the "increment" message and a __whenMoreResolved
message to update "result", and a second __whenMoreResolved to run the
when block.
2. [remote] gets the "increment" message
3. [remote] performs the increment
4. [remote] gets the __whenMoreResolved message
5. [remote] sends the result (6) back
6. [start] gets the result
7. [start] resolves "result"
8. [remote] gets the second __whenMoreResolved message
9. [remote] sends the result back again
10. [start] gets the result
11. [start] runs the when block
This all seems a bit excessive. Could the local promise remember that
it's just sent a __whenMoreResolved and avoid sending a second one
somehow?
But assuming it's necessary, how do I simplify the resulting graph?
Should the "result" value be linked somehow in the causality chain, so
that anyone sending to it again gets linked to the point where it was
set?
Thanks,
On 2 June 2010 17:49, Tyler Close <[email protected]> wrote:
> The message sender generates a GUID for the message. It's unspecified
> how the sender and receiver coordinate the message identifier. The
> Waterken Server identifies an inter-vat message by a GUID for the
> vat-to-vat connection and a message serial number. The connection GUID
> is the hash of the connection key. The connection key and the message
> serial number are transmitted along with the message content itself
> for all messages, regardless of whether or not Causeway logging is
> enabled. The same identifiers are also used to ensure at-most-once
> message delivery. For intra-vat messages, the Waterken Server uses a
> different algorithm.
>
> --Tyler
>
> On Wed, Jun 2, 2010 at 8:53 AM, Thomas Leonard
> <tal-v5nx5w6akNyLE8xUarVfuPLx9OUvmyODWmv/[email protected]> wrote:
>> I probably won't have any time to work on this. One question though from
>> a quick look: where does the message ID come from?
>>
>>
>> On Mon, 2010-05-24 at 08:03 -0700, Terry Stanley wrote:
>>> Hi Thomas,
>>>
>>> The pages at <http://wiki.erights.org/wiki/Causeway> and
>>> <http://wiki.erights.org/wiki/Causeway_Platform_Developer> are still
>>> rough and incomplete, but should help get you started. Please let me
>>> know of any questions you have.
>>>
>>> --Terry
>>>
>>>
>>> On Fri, May 21, 2010 at 9:05 AM, Terry Stanley <[email protected]> wrote:
>>> > Hello Thomas,
>>> >
>>> > This weekend I expect to update the erights wiki with experience to
>>> > date instrumenting platforms to generate Causeway's trace logs.
>>> > Recently Tyler Close & Tom Van Cutsem and I discussed their
>>> > experiences with Waterken & AmbientTalk (respectively). The wiki will
>>> > be a good place for you to start to get an idea of what's involved. It
>>> > will include examples of the set of events that describe promise
>>> > behavior (Waterken & AmbientTalk generate different events),
>>> > difficulties of capturing stack traces, performance considerations,
>>> > and so on.
>>> >
>>> > Initially, Causeway worked only with E-on-Java and we had an ad-hoc
>>> > trace log format. Subsequently, Tyler defined the current
>>> > language-neutral json format. We expected to have E generate the new
>>> > format but had to back out of that effort. We just didn't have the
>>> > time.
>>> >
>>> > My intent is for the wiki experience report to simplify the effort of
>>> > generating Causeway trace logs and to prevent someone from being
>>> > blind-sided by some problem. So, perhaps, you'll be my first test
>>> > case. Feedback would be very much appreciated.
>>> >
>>> > -- Terry
>>> >
>>> _______________________________________________
>>> e-lang mailing list
>>> [email protected]
>>> http://www.eros-os.org/mailman/listinfo/e-lang
>>
>> --
>> Dr Thomas Leonard
>> IT Innovation Centre
>> 2 Venture Road
>> Southampton
>> Hampshire SO16 7NP
>>
>> Tel: +44 0 23 8076 0834
>> Fax: +44 0 23 8076 0833
>> mailto:tal-v5nx5w6akNyLE8xUarVfuPLx9OUvmyODWmv/[email protected]
>> http://www.it-innovation.soton.ac.uk
>>
>> _______________________________________________
>> e-lang mailing list
>> [email protected]
>> http://www.eros-os.org/mailman/listinfo/e-lang
>>
>
>
>
> --
> "Waterken News: Capability security on the Web"
> http://waterken.sourceforge.net/recent.html
>
> _______________________________________________
> e-lang mailing list
> [email protected]
> http://www.eros-os.org/mailman/listinfo/e-lang
>
--
Dr Thomas Leonard http://0install.net/
GPG: 9242 9807 C985 3C07 44A6 8B9A AE07 8280 59A5 3CC1
GPG: DA98 25AE CAD0 8975 7CDA BD8E 0713 3F96 CA74 D8BA
_______________________________________________
e-lang mailing list
[email protected]
http://www.eros-os.org/mailman/listinfo/e-lang
causality.log
(text/x-log, 13.5 KB)
[
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 0,
"turn" : {
"loop" : "start",
"number" : 226,
}
},
"message" : "vw5ifyudozlcwtsggiqdgbnmqiqkdu35-agjeij33ywatxx2anaz42qkyrvjeeyki-4",
"text" : "increment",
"trace" : {"calls" : [{"name": "send/3", "source": "/home/talex/src/e/src/esrc/scripts/test/causeway/e/sources/increment.e", "span": [[21]]}, {"name": "__main$runTest$_#run/1", "source": "/home/talex/src/e/src/esrc/scripts/test/causeway/e/sources/increment.e", "span": [[16]]}, {"name": "OneArgFunc#run(Object)", "source": "-", "span": [[0]]}] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 1,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 59,
}
},
"message" : "vw5ifyudozlcwtsggiqdgbnmqiqkdu35-agjeij33ywatxx2anaz42qkyrvjeeyki-4",
"trace" : {"calls" : [{"name": "<remote><-increment(5)", "source": "-"}
] }
},
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 2,
"turn" : {
"loop" : "start",
"number" : 226,
}
},
"message" : "vw5ifyudozlcwtsggiqdgbnmqiqkdu35-agjeij33ywatxx2anaz42qkyrvjeeyki-5",
"text" : "__whenMoreResolved",
"trace" : {"calls" : [{"name": "whenResolved/2", "source": "-", "span": [[0]]}, {"name": "__main$runTest$_#run/1", "source": "/home/talex/src/e/src/esrc/scripts/test/causeway/e/sources/increment.e", "span": [[16]]}, {"name": "OneArgFunc#run(Object)", "source": "-", "span": [[0]]}] }
},
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 3,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 59,
}
},
"message" : "newVirtualSeedVat_60",
"text" : "<remote>.increment(5)",
"trace" : {"calls" : [{"name": "<init>", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[49]]}, {"name": "<init>", "source": "org/erights/e/elib/vat/PendingDelivery.java", "span": [[65]]}, {"name": "qSendAll", "source": "org/erights/e/elib/vat/Vat.java", "span": [[407]]}, {"name": "qSendAll", "source": "org/erights/e/elib/vat/Vat.java", "span": [[383]]}, {"name": "sendAll", "source": "org/erights/e/elib/vat/Vat.java", "span": [[150]]}, {"name": "sendAll", "source": "org/erights/e/elib/prim/E.java", "span": [[343]]}, {"name": "execDeliverOp", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[881]]}, {"name": "receiveMsg", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[762]]}, {"name": "processMessage", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[729]]}, {"name": "newIncomingMsg", "source": "net/vattp/data/VatTPConnection.java", "span": [[727]]}, {"name": "newIncomingMsg", "source": "net/vattp/data/DataPath.java", "span": [[691]]}, {"name": "run", "source": "net/vattp/data/DataCommThunk.java", "span": [[207]]}, {"name": "innerRun", "source": "org/erights/e/elib/vat/PendingCall.java", "span": [[75]]}, {"name": "run", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[80]]}, {"name": "run", "source": "org/erights/e/elib/vat/HeadlessRunner.java", "span": [[174]]}, {"name": "run", "source": "java/lang/Thread.java", "span": [[636]]}] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 4,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 60,
}
},
"message" : "newVirtualSeedVat_60",
"trace" : {"calls" : [{"name": "<remote>.increment(5)", "source": "-"}
] }
},
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 5,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 60,
}
},
"message" : "newVirtualSeedVat_62",
"text" : "6 <- __whenMoreResolved(<Far ref>)",
"trace" : {"calls" : [{"name": "<init>", "source": "org/erights/e/elib/vat/PendingDelivery.java", "span": [[81]]}, {"name": "qSendMsg", "source": "org/erights/e/elib/vat/Vat.java", "span": [[337]]}, {"name": "sendMsg", "source": "org/erights/e/elib/ref/NearRef.java", "span": [[112]]}, {"name": "deliverAll", "source": "org/erights/e/elib/ref/BufferingRef.java", "span": [[191]]}, {"name": "resolve", "source": "org/erights/e/elib/ref/LocalResolver.java", "span": [[96]]}, {"name": "resolve", "source": "org/erights/e/elib/ref/LocalResolver.java", "span": [[108]]}, {"name": "innerRun", "source": "org/erights/e/elib/vat/PendingDelivery.java", "span": [[129]]}, {"name": "run", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[80]]}, {"name": "run", "source": "org/erights/e/elib/vat/HeadlessRunner.java", "span": [[174]]}, {"name": "run", "source": "java/lang/Thread.java", "span": [[636]]}] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 6,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 62,
}
},
"message" : "newVirtualSeedVat_62",
"trace" : {"calls" : [{"name": "6 <- __whenMoreResolved(<Far ref>)", "source": "-"}
] }
},
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 7,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 62,
}
},
"message" : "newVirtualSeedVat_64",
"text" : "6.__whenMoreResolved(<Far ref>)",
"trace" : {"calls" : [{"name": "<init>", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[49]]}, {"name": "<init>", "source": "org/erights/e/elib/vat/PendingDelivery.java", "span": [[65]]}, {"name": "qSendAllOnly", "source": "org/erights/e/elib/vat/Vat.java", "span": [[359]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/vat/Vat.java", "span": [[143]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/prim/E.java", "span": [[426]]}, {"name": "innerRun", "source": "org/erights/e/elib/vat/PendingDelivery.java", "span": [[115]]}, {"name": "run", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[80]]}, {"name": "run", "source": "org/erights/e/elib/vat/HeadlessRunner.java", "span": [[174]]}, {"name": "run", "source": "java/lang/Thread.java", "span": [[636]]}] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 8,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 64,
}
},
"message" : "newVirtualSeedVat_64",
"trace" : {"calls" : [{"name": "6.__whenMoreResolved(<Far ref>)", "source": "-"}
] }
},
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 9,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 64,
}
},
"message" : "agjeij33ywatxx2anaz42qkyrvjeeyki-vw5ifyudozlcwtsggiqdgbnmqiqkdu35-3",
"text" : "run",
"trace" : {"calls" : [{"name": "static MirandaMethods#null", "source": "-", "span": [[0]]}] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 10,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 65,
}
},
"message" : "vw5ifyudozlcwtsggiqdgbnmqiqkdu35-agjeij33ywatxx2anaz42qkyrvjeeyki-5",
"trace" : {"calls" : [{"name": "6<-__whenMoreResolved(<Far ref>)", "source": "-"}
] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 11,
"turn" : {
"loop" : "start",
"number" : 233,
}
},
"message" : "agjeij33ywatxx2anaz42qkyrvjeeyki-vw5ifyudozlcwtsggiqdgbnmqiqkdu35-3",
"trace" : {"calls" : [{"name": "<a DelayedRedirector>(6)", "source": "-"}
] }
},
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 12,
"turn" : {
"loop" : "start",
"number" : 233,
}
},
"message" : "start_234",
"text" : "<a DelayedRedirector>(6)",
"trace" : {"calls" : [{"name": "<init>", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[49]]}, {"name": "<init>", "source": "org/erights/e/elib/vat/PendingDelivery.java", "span": [[65]]}, {"name": "qSendAllOnly", "source": "org/erights/e/elib/vat/Vat.java", "span": [[359]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/vat/Vat.java", "span": [[143]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/prim/E.java", "span": [[426]]}, {"name": "execDeliverOnlyOp", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[829]]}, {"name": "receiveMsg", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[748]]}, {"name": "processMessage", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[729]]}, {"name": "newIncomingMsg", "source": "net/vattp/data/VatTPConnection.java", "span": [[727]]}, {"name": "newIncomingMsg", "source": "net/vattp/data/DataPath.java", "span": [[691]]}, {"name": "run", "source": "net/vattp/data/DataCommThunk.java", "span": [[207]]}, {"name": "innerRun", "source": "org/erights/e/elib/vat/PendingCall.java", "span": [[75]]}, {"name": "run", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[80]]}, {"name": "run", "source": "org/erights/e/elib/vat/HeadlessRunner.java", "span": [[174]]}, {"name": "run", "source": "java/lang/Thread.java", "span": [[636]]}] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 14,
"turn" : {
"loop" : "start",
"number" : 234,
}
},
"message" : "start_234",
"trace" : {"calls" : [{"name": "<a DelayedRedirector>(6)", "source": "-"}
] }
},
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 13,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 65,
}
},
"message" : "newVirtualSeedVat_67",
"text" : "6.__whenMoreResolved(<Far ref>)",
"trace" : {"calls" : [{"name": "<init>", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[49]]}, {"name": "<init>", "source": "org/erights/e/elib/vat/PendingDelivery.java", "span": [[65]]}, {"name": "qSendAllOnly", "source": "org/erights/e/elib/vat/Vat.java", "span": [[359]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/vat/Vat.java", "span": [[143]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/prim/E.java", "span": [[426]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/ref/NearRef.java", "span": [[129]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/ref/SwitchableRef.java", "span": [[154]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/prim/E.java", "span": [[424]]}, {"name": "execDeliverOnlyOp", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[829]]}, {"name": "receiveMsg", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[748]]}, {"name": "processMessage", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[729]]}, {"name": "newIncomingMsg", "source": "net/vattp/data/VatTPConnection.java", "span": [[727]]}, {"name": "newIncomingMsg", "source": "net/vattp/data/DataPath.java", "span": [[691]]}, {"name": "run", "source": "net/vattp/data/DataCommThunk.java", "span": [[207]]}, {"name": "innerRun", "source": "org/erights/e/elib/vat/PendingCall.java", "span": [[75]]}, {"name": "run", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[80]]}, {"name": "run", "source": "org/erights/e/elib/vat/HeadlessRunner.java", "span": [[174]]}, {"name": "run", "source": "java/lang/Thread.java", "span": [[636]]}] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 15,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 67,
}
},
"message" : "newVirtualSeedVat_67",
"trace" : {"calls" : [{"name": "6.__whenMoreResolved(<Far ref>)", "source": "-"}
] }
},
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 16,
"turn" : {
"loop" : "newVirtualSeedVat",
"number" : 67,
}
},
"message" : "agjeij33ywatxx2anaz42qkyrvjeeyki-vw5ifyudozlcwtsggiqdgbnmqiqkdu35-4",
"text" : "run",
"trace" : {"calls" : [{"name": "static MirandaMethods#null", "source": "-", "span": [[0]]}] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 17,
"turn" : {
"loop" : "start",
"number" : 239,
}
},
"message" : "agjeij33ywatxx2anaz42qkyrvjeeyki-vw5ifyudozlcwtsggiqdgbnmqiqkdu35-4",
"trace" : {"calls" : [{"name": "<a WhenResolvedReactor>(6)", "source": "-"}
] }
},
{
"class" : ["org.ref_send.log.Sent", "org.ref_send.log.Event"],
"anchor" : {
"number" : 18,
"turn" : {
"loop" : "start",
"number" : 239,
}
},
"message" : "start_240",
"text" : "<a WhenResolvedReactor>(6)",
"trace" : {"calls" : [{"name": "<init>", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[49]]}, {"name": "<init>", "source": "org/erights/e/elib/vat/PendingDelivery.java", "span": [[65]]}, {"name": "qSendAllOnly", "source": "org/erights/e/elib/vat/Vat.java", "span": [[359]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/vat/Vat.java", "span": [[143]]}, {"name": "sendAllOnly", "source": "org/erights/e/elib/prim/E.java", "span": [[426]]}, {"name": "execDeliverOnlyOp", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[829]]}, {"name": "receiveMsg", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[748]]}, {"name": "processMessage", "source": "net/captp/jcomm/CapTPConnection.java", "span": [[729]]}, {"name": "newIncomingMsg", "source": "net/vattp/data/VatTPConnection.java", "span": [[727]]}, {"name": "newIncomingMsg", "source": "net/vattp/data/DataPath.java", "span": [[691]]}, {"name": "run", "source": "net/vattp/data/DataCommThunk.java", "span": [[207]]}, {"name": "innerRun", "source": "org/erights/e/elib/vat/PendingCall.java", "span": [[75]]}, {"name": "run", "source": "org/erights/e/elib/vat/PendingEvent.java", "span": [[80]]}, {"name": "run", "source": "org/erights/e/elib/vat/HeadlessRunner.java", "span": [[174]]}, {"name": "run", "source": "java/lang/Thread.java", "span": [[636]]}] }
},
{
"class" : ["org.ref_send.log.Got", "org.ref_send.log.Event"],
"anchor" : {
"number" : 19,
"turn" : {
"loop" : "start",
"number" : 240,
}
},
"message" : "start_240",
"trace" : {"calls" : [{"name": "<a WhenResolvedReactor>(6)", "source": "-"}
] }
},
out.svg
(image/svg+xml, 9 KB) - not displayed