logging: eventual() causality tracing

[Brian Warner]

Zooko mentioned that some recent debugging work of his would have gone faster if eventual-sends didn't break the chain of causality in stack traces. Specifically, when you have code like the following:

def parent():
    eventual.eventually(child)

def child():
    raise OopsError

Then the "unhandled error in Deferred" -type stuff logs the OopsError?, but the parent of the stack that it records is going to be the eventual-send code's _turn method, and parent is nowhere visible on that stack.

It would probably suffice to have eventual.eventually() record a single frame of the stack that calls into it, and store that next to the callback+args tuple. Call this the "causality record", since other logging improvements are going to be using similar concepts (in which the record might include the whole stack, or might have a remote message number, or a turn number, or perhaps an application-generated explicit context structure).

The trickier part will be how to include this causality record in with the resulting log messages. When foolscap's 'flog' mechanism grows to the point where it is involved in recording Unhandled Error In Deferreds and the like, it could crawl the stack, locate the _turn() frame, extract the causality record, then include it in the message it is generating. (likewise when a remote call is what triggered the turn, the request-id and remote tub-id should be used as the causality record).