Causeway Platform Developer

From Erights

(Difference between revisions)
Jump to: navigation, search
Line 1: Line 1:
== Instrumenting a Platform to Generate Causeway Trace Logs ==
== Instrumenting a Platform to Generate Causeway Trace Logs ==
-
Introduction, communicating events loops
+
Causeway supports debugging distributed programs built on the communicating event loops concurrency model. This document describes Causeway's language-neutral trace log format and explains how to instrument a platform to generate trace logs.
 +
 
 +
For concreteness, we show the trace log records generated for a simple distributed program.
 +
 
 +
Our example program implements a procedure for handling new purchase orders. Before an order is placed, certain conditions must be met: the item is in stock and available, the customer’s account is in good standing, and the delivery options are up to date. An object residing in the "buyer" process (or vat) has remote references to objects residing in the "product" and "accounts" vats. The buyer queries the remote objects with asynchronous (non-blocking) message sends. The answers from the asynchronous inquiries must be collected and examined. The order is placed only if all requirements are satisfied.
 +
 
 +
Starting with one-way asynchronous messages, two patterns for handling responses are ''continuation-passing'' and ''promises''. In continuation-passing a request carries a callback argument to which a response should be sent.
 +
We refer to this as ''Ajax-style'' messaging, as it is the dominant pattern for web application development. A promise (''future'', in AmbientTalk) is a place-holder for the answer to a query; when the answer becomes available the promise resolves to that value.
 +
 
 +
Waterken, AmbientTalk and Causeway support both styles of response handling.
-
* Waterken
 
-
** promises
 
-
* AmbientTalk
 
-
** futures
 
=== Getting Started ===
=== Getting Started ===
Line 24: Line 29:
* Browse the example programs in Causeway, e.g., Help >> Open Waterken Example (Ajax-style).
* Browse the example programs in Causeway, e.g., Help >> Open Waterken Example (Ajax-style).
-
 
-
=== Support Tools ===
 
* Enable Causeway's debug view
* Enable Causeway's debug view
Line 40: Line 43:
[[Image:debug-view.png]]
[[Image:debug-view.png]]
-
 
-
* Support for visualizing graph filter algorithm
 
-
 
-
Your first traces are likely to be noisy and Causeway's views, baffling. It can take some careful consideration and cleverness to figure out why and what to do about it. Simple filters (e.g., hiding stack frames, options for more or less detail) are necessary but not sufficient. The right abstractions must be found to enhance program understanding, while maintaining causality. Currently, Causeway does not support user-specified filters that manipulate the message graph (DAG) structure. Our approach to debugging our filtering algorithm is described HERE. Once we have more experience, we expect to support user-specified filters.
 
== Causeway's Trace Log Format ==
== Causeway's Trace Log Format ==
Line 71: Line 70:
=== Logging Ajax-style Messaging in Waterken ===
=== Logging Ajax-style Messaging in Waterken ===
-
Our example program implements a distributed procedure for handling new purchase orders. Before an order is placed, certain conditions must be met: the item is in stock and available, the customer's account is in good standing, and the delivery options are up to date.
+
The code snippet below shows the 3 queries being fired off. All 3 answers must be examined before the order is placed. Collecting the answers is handled by an <tt>AsyncAnd</tt> object. To collect the three answers, <tt>teller</tt> is passed as an argument to each of the remote queries, serving as a callback function.
-
 
+
-
An object residing in the "buyer" vat has remote references to objects residing in the "product" and "accounts" vats. The buyer queries the remote objects with asynchronous (non-blocking) message sends.
+
-
 
+
-
The code snippet below shows the 3 queries being fired off. All 3 answers must be examined before the order is placed. Collecting the answers is handled by an <tt>AsyncAnd</tt> object. To collect the three answers, teller is passed as an argument to each of the remote queries, serving as a callback function.
+
<pre>
<pre>

Revision as of 23:58, 11 June 2010

Contents

Instrumenting a Platform to Generate Causeway Trace Logs

Causeway supports debugging distributed programs built on the communicating event loops concurrency model. This document describes Causeway's language-neutral trace log format and explains how to instrument a platform to generate trace logs.

For concreteness, we show the trace log records generated for a simple distributed program.

Our example program implements a procedure for handling new purchase orders. Before an order is placed, certain conditions must be met: the item is in stock and available, the customer’s account is in good standing, and the delivery options are up to date. An object residing in the "buyer" process (or vat) has remote references to objects residing in the "product" and "accounts" vats. The buyer queries the remote objects with asynchronous (non-blocking) message sends. The answers from the asynchronous inquiries must be collected and examined. The order is placed only if all requirements are satisfied.

Starting with one-way asynchronous messages, two patterns for handling responses are continuation-passing and promises. In continuation-passing a request carries a callback argument to which a response should be sent. We refer to this as Ajax-style messaging, as it is the dominant pattern for web application development. A promise (future, in AmbientTalk) is a place-holder for the answer to a query; when the answer becomes available the promise resolves to that value.

Waterken, AmbientTalk and Causeway support both styles of response handling.


Getting Started

  • See Causeway for user documentation, which includes instructions for launching Causeway from a command line shell.
  • See HP Labs Technical Report at www.hpl.hp.com/techreports/2009/HPL-2009-78.html for a more in-depth discussion of the material presented here. A careful read is not necessary but a quick skim to see what's there is a good idea.

This documentation assumes an understanding of the purchase-order example program.

  • Read the source code. It's part of the E distribution and can be found here.
   e/src/esrc/scripts/test/causeway/waterken/sources
   e/src/esrc/scripts/test/causeway/ambientTalk/sources

Also, we're asking that you write a version of the purchase-order example that runs on your platform, as one of your first test cases. It's best to start with the Ajax-style continuation-passing, using callbacks. This approach is less expressive than promises, but generating the trace log is more straightforward.

  • Browse the example programs in Causeway, e.g., Help >> Open Waterken Example (Ajax-style).
  • Enable Causeway's debug view

Setting Causeway's debug flag enables a debug view. As events are selected in the viewer, the debug view shows the corresponding trace record in the log file. This is a very useful option, especially in the beginning, when things aren't quite working.

$ rune -Dcauseway_debug=true causeway.e-swt 


(Note: When this debug option is set, Causeway's JSON parser uses getTwine(). This is an inefficient algorithm which is not likely to change anytime soon. The trace logs for the example programs are roughly 20K; the poor performance is noticed with logs > 250K.)


Image:debug-view.png


Causeway's Trace Log Format

Causeway supports the trace log format defined by Tyler Close at waterken.sourceforge.net/debug/.

We will explain this format, and how to get your platform to generate it, in three steps: Simple Ajax (below), Ajax with promotion, and full promises.


Simple event types


When causality tracing is on the events are logged as follows.

Event Record type
An eventual send to an object Sent
A message delivery, starting a new turn Got
Programmer logs a comment Comment


Logging Ajax-style Messaging in Waterken

The code snippet below shows the 3 queries being fired off. All 3 answers must be examined before the order is placed. Collecting the answers is handled by an AsyncAnd object. To collect the three answers, teller is passed as an argument to each of the remote queries, serving as a callback function.

    Callback teller = new AsyncAnd(_, 3, checkAnswers(_, inventory));

    _._(inventory).partInStock(partNo, teller);
    _._(creditBureau).checkCredit(name, teller);
    _._(shipper).canDeliver(profile, teller);


Consider the sequence of events shown below.

Ajax-style message send

  • a remote inventory object is queried for the availability of a part
  • the inventory object reports true to teller, a callback object


The eventual send to the inventory object has two log entries: a Sent and its corresponding Got.

    "class" : [ "org.ref_send.log.Sent", "org.ref_send.log.Event" ],
    "anchor" : {
      "number" : 2,
      "turn" : {
        "loop" : "http://localhost:8080/-/buyer/",
        "number" : 3
      }
    },
    "message" : "qvet6lrs4zsfpv-2-0",
    "timestamp" : 1275338022120,
    "trace" : {
      "calls" : [ {
          "name" : "Main.Buy.fulfill",
          "source" : "org/waterken/simple_purchase_ajax/Main.java",
          "span" : [ [ 68 ] ]
        }, {
          "name" : "Main.Buy.fulfill",
          "source" : "org/waterken/simple_purchase_ajax/Main.java",
          "span" : [ [ 48 ] ]
        } ]
    }
    "class" : [ "org.ref_send.log.Got", "org.ref_send.log.Event" ],
    "anchor" : {
      "number" : 1,
      "turn" : {
        "loop" : "http://localhost:8080/-/buyer/product/",
        "number" : 2
      }
    },
    "message" : "qvet6lrs4zsfpv-2-0",
    "timestamp" : 1275338022291,
    "trace" : {
      "calls" : [ {
          "name" : "InventoryMaker.InventoryX.partInStock",
          "source" : "org/waterken/simple_purchase_ajax/InventoryMaker.java"
        } ]
    }
  • In the Sent trace record:
    • anchor uniquely identifies the origin of this message send as the 2nd messaging event from the buyer vat, turn 3.
    • message is a generated string which uniquely identifies a message.
    • trace is the stack capture at the point of the message send.

(Note: The loop field identifies the vat by URI. By convention, Causeway picks up the part following "/-/", in this case buyer, for a short display name.)

(Note: The timestamp field is optional. Currently, Causeway ignores it, so it's not shown in the remaining trace records.)

The corresponding Got has a matching message. The message delivery in the product vat starts a new turn, turn 2. Being at the top of a new turn, there is limited stack capture and getting a source span through Java reflection, is not practical.


Reporting true to teller has two log entries: a Sent and its corresponding Got.

    "class" : [ "org.ref_send.log.Sent", "org.ref_send.log.Event" ],
    "anchor" : {
      "number" : 2,
      "turn" : {
        "loop" : "http://localhost:8080/-/buyer/product/",
        "number" : 2
      }
    },
    "message" : "4qjohg533s6cjn-1-0",
    "trace" : {
      "calls" : [ {
          "name" : "InventoryMaker.InventoryX.partInStock",
          "source" : "org/waterken/simple_purchase_ajax/InventoryMaker.java",
          "span" : [ [ 19 ] ]
        } ]
    }
    "class" : [ "org.ref_send.log.Got", "org.ref_send.log.Event" ],
    "anchor" : {
      "number" : 1,
      "turn" : {
        "loop" : "http://localhost:8080/-/buyer/",
        "number" : 10
      }
    },
    "message" : "4qjohg533s6cjn-1-0",
    "trace" : {
      "calls" : [ {
          "name" : "AsyncAnd.run",
          "source" : "org/waterken/simple_purchase_ajax/AsyncAnd.java"
        } ]
    }

The reply to the query is the 2nd messaging event from the product vat, turn 2.

The corresponding Got has a matching message. The message delivery in the buyer vat starts a new turn, turn 10.


In the Causeway viewer, individual tree items represent events and their descriptive labels depend on the information available in the trace record for the event.


Tree item labels


To present the most useful information available, Causeway labels tree items according to the following priority.

  1. User comments specified in the text field, prefixed with "#".
  2. Source code specified in the top call stack object. The trace object must include a span.
  3. Source file and function name specified in top call stack object. The trace object must include a name and source.
  4. If none of the above, the label is a Causeway-generated comment, prefixed with "##", e.g., ## unknown sender.


The resulting process-order view and message-order view are shown below.

Simple process-order view and message-order view

Personal tools
more tools