add tracing API, with docs

[warner]

refs #36

This seems useful for my own debugging purposes, where the logging function is just print().

Some questions still in my mind:

• Is the tracing function sufficient to collect transition-coverage information, for Test helper that asserts a given transition occurred #37/Test helper that asserts all transitions occurred #38?
• This replaces the generator of outputs with a list, which probably inadvertently fixes Not all outputs get run if the collector does not exhaust the generator. #30
• The use of output=None vs output=(string) doesn't really capture the causality of transitions and their output functions being invoked. A properly structured logging framework (like Eliot or Foolscap) would be unsatisfied. Some other approaches would be:
  • register two separate logging functions (one for transitions, another for outputs), and have the return value from the first get passed as an extra argument into the second
  • pass an additional argument with some sort of (hashable) opaque token, that we promise will be identical for all calls involving the same transition
• should we make the __str__ of States/Inputs/Outputs be just the name of the method, and then have the tracer use str(oldState) instead of oldState._name()? I have a patch to improve the __str__ elsewhere, but I had been planning to make it be e.g. "State($name)" rather than just "$name".
• are y'all comfortable with changing the return value of transition() to be a tuple like that? And with defining the outTracer closure inside transition()? It seemed like the easiest way to get a linked tracing function into doInput() where the outputs actually get run. If we change the way that outputs get logged, maybe we could avoid doing that, somehow.

[coveralls]

Coverage remained the same at 100.0% when pulling e4a9cf3 on warner:36-tracing into 9493b61 on glyph:master.

[glyph]

I am inclined to approve, but I think @markrwilliams might have some strong opinions about tracing and I'd like to confirm that he's happy with this API as well before committing to it.

[warner]

I had another idea for connecting the "entering transition" message with all the "executing an output" messages: what if the log function can return a callable if it wants them? We'd promise to call the function once when entering the transition, but if it returns non-None then we call that function with each output.

That would remove the closure in transition(), and would allow the caller to do whatever sort of causality recording they like (they'd be obligated to make a closure for each transition, but if they don't care then the default of returning None means we do no extra work).

This would make it behave somewhat like sys.settrace().

[markrwilliams]

@warner Thanks for this PR! The approach looks great, but I prefer this:

I had another idea for connecting the "entering transition" message with all the "executing an output" messages: what if the log function can return a callable if it wants them? We'd promise to call the function once when entering the transition, but if it returns non-None then we call that function with each output.

...to indicating that a tracing call represents an input because its output argument is None. I'm pretty sure I'd misuse that API. If you have the time, please add this to the PR, and if not, I'm happy to do it!

I'm also cagey about identifying inputs, states, and outputs by their names. Does the code do this so that MethodicalInput and company can remain private? If so, I see the value in that, but I worry that strings will make it easier for tests and code to get out of sync (that is, getting an opaque test failure instead of an AttributeError.) At the same time, the Graphviz integration depends on names of objects as well, so I suppose this is hypocritical. I also worry that only having the names of things will make the traversal code for #37 and #38 less precise, because it will have to infer the type of an object by its position, and then compare names, rather than relying on an identity check.

These concerns are too small to prevent me from merging this PR after change to the tracing API, but I'd be interested in your thoughts.

[warner]

Ok, I'll implement the return-a-callable approach. I like that better too.

I figured I'd pass strings into the logging callback to make it easier to print concise messages. I could pass the raw objects in, but then:

• the repr()/str() of each is pretty verbose. Inputs just look like <function go2 at 0x10a233ed8>, but Outputs are MethodicalOutput(method=<function out2 at 0x10ea08d70>), and States are MethodicalState(method=<function end at 0x106c2ab18>). If the logging function's signature makes it clear which arguments are outputs and which are states, then the only useful piece of information in that str() is the function name, which is buried in the middle. If we went this way, I'd want a stable .name() API to retrieve just the name for my logging function, and we'd need to give the tracer a MethodicalInput instead of the wrapper function (so there's something to call .name() upon).
• you can't even reach a MethodicalOutput from outside the class (since Automat tries to hard to keep them hidden from you), so there's nothing to compare-by-identity anyways. States are reachable, but I suspect they're not supposed to be.

I have a branch that changes the str() for Outputs and States to be just the name, which might clean up the internal code a bit (removing the _name() method), which would have the side-effect of making eval-time errors more conside (like the "your method signatures don't match" one), which currently print the same verbose MethodicalOutput repr.

Let's think for a minute about the #37/#38 issues: we need a way, from outside the state machine, to refer to States, Inputs, Outputs, and transitions. At the moment, Automat tries very hard to hide these:

s = SampleObject()
print(s.mm)
-> AttributeError: MethodicalMachine is an implementation detail
print(s.begin_state)
-> MethodicalState(method=<function begin_state at 0x123>)
print(s.go_input)
-> <function go_input at 0x123>
print(s.output)
-> AttributeError: SampleObject.output is a state-machine output method; to produce this output, call an input method instead.

so we can currently get at Inputs and States, but not Outputs (and I think States might be an accident). If I'm grokking the Automat philosophy properly, client code has no need to see a State, so they ought to be hidden too. And there's certainly no s.current_state accessor right now.

Transitions don't have a distinct object: they're represented internally by tuples of states and inputs.

#37 wants a way for a test class to refer to a transition, which maybe means a pair of States. I can see uses for things like assertTransitionedFrom(state1, to=state2), assertReachedAllOf(*states), and assertCurrentlyInState(state1). None of those happen to need Inputs or Outputs.

There are multiple ways to get from one state to another (different Inputs, with different Outputs), so you might want to be more precise about your expectations, and refer to Inputs too. assertTransitionedFrom(state1, via=input1, to=state2). That requires that Inputs remain visible.

Would we want a test to assert something about the outputs? assertOutputCalled(output1)? Is there any other/easier way to check that this had happened? (I'm thinking of mock.patch, but since the output function has been wrapped a couple of times, that might not really be an option).

#38 might want something like a tracing function that accumulates transition coverage during a particular sequence of events (on a concrete instance), as (from_state, input, to_state) tuples, then compares it against the set of all known transitions (obtained from the abstract MethodicalMachine definition). If it's really that binary, then we don't need to expose any of the internals until something fails, and then our implementation can decide what strings to put into the exception. We do need a way for the test method to reach inside the concrete state machine and extract the abstract MethodicalMachine, but that doesn't need to be a public API.

So, should we rely on States remaining visible, and write these other APIs to reference them? Should we hide States but then add some sort of debug API that lets you access the underlying MethodicalMachine, from which you could read the MethodicalState object without the AttributeError?

The things we expose for #37/#38 should probably influence what we pass to the tracing function for this ticket, if we're offering application code and/or tests the opportunity to compare them against each other.

[warner]

(re-pushing this branch as-is, rebased, without the return-a-callable change yet, just to make sure it works on py3.6, now that we have coverage for that).

[coveralls]

Coverage remained the same at 100.0% when pulling d6ba643 on warner:36-tracing into 37a1491 on glyph:master.

[coveralls]

Coverage remained the same at 100.0% when pulling 5dff07a on warner:36-tracing into 37a1491 on glyph:master.

[markrwilliams]

@warner I'm comfortable with using strings for now. As we discussed offline, I think Automat should expose a read-only view on the underlying Automaton for debugging and testing. I haven't gotten very far with what that would look like, but as you suggested, tackling #37/#38 will meaningfully inform it. Unfortunately I don't have time to do so right now, so I think it makes sense to prevent the future from stopping the present.

It may be the case that none of these APIs end up being public, of course, so I think your suggestion of marking the tracing API as unstable is a good one. Can you add that to debugging.md and then merge?

[warner]

Ok, will do. I want to update my magic-wormhole code to match the new API, make sure it feels right, then I'll update the docs to caution folks against relying on this API and then land this.

[glyph]

I don't believe in "provisional" APIs :).

Just make the API private. If someone wants to call it, they can; but, as the rule is with any other private API, if you use it, you need to pin your dependency.

[warner]

Righto. The new recommended sample code will then look like:

    m = MethodicalMachine()
    set_trace = getattr(m, "_setTrace", lambda self, f: None)

which would make an app at least somewhat future-proof. For my code, I'm only actually calling set_trace when I'm debugging, so using a tolerant getattr means the app keeps working if/when the private API goes away.

[coveralls]

Coverage remained the same at 100.0% when pulling c8153cf on warner:36-tracing into 37a1491 on glyph:master.

[warner]

Ok, travis approves, so I'll land this now. Thanks for all your feedback!