[engine] refine exception output

1. Output exception details on leaf trace nodes as opposed to lots of repetitions as linked in the bug.
2. newline Throw for clarity.

Testing Done:
https://travis-ci.org/pantsbuild/pants/builds/138217773

[tw-mbp-yic pants (3535_b)]$ ./pants --enable-v2-engine dependees examples/tests/::
Exception caught: (<class 'pants.build_graph.address_lookup_error.AddressLookupError'>)
  File "/Users/yic/workspace/pants/src/python/pants/bin/pants_exe.py", line 50, in <module>
    main()
  File "/Users/yic/workspace/pants/src/python/pants/bin/pants_exe.py", line 44, in main
    PantsRunner(exiter).run()
  File "/Users/yic/workspace/pants/src/python/pants/bin/pants_runner.py", line 57, in run
    options_bootstrapper=options_bootstrapper)
  File "/Users/yic/workspace/pants/src/python/pants/bin/pants_runner.py", line 46, in _run
    return LocalPantsRunner(exiter, args, env, options_bootstrapper=options_bootstrapper).run()
  File "/Users/yic/workspace/pants/src/python/pants/bin/local_pants_runner.py", line 53, in run
    self._maybe_profiled(self._run)
  File "/Users/yic/workspace/pants/src/python/pants/bin/local_pants_runner.py", line 50, in _maybe_profiled
    runner()
  File "/Users/yic/workspace/pants/src/python/pants/bin/local_pants_runner.py", line 93, in _run
    self._exiter).setup()
  File "/Users/yic/workspace/pants/src/python/pants/bin/goal_runner.py", line 84, in __init__
    build_graph)
  File "/Users/yic/workspace/pants/src/python/pants/bin/goal_runner.py", line 99, in _select_buildgraph
    return graph_helper.create_graph(root_specs)
  File "/Users/yic/workspace/pants/src/python/pants/bin/engine_initializer.py", line 70, in create_graph
    for _ in graph.inject_specs_closure(spec_roots):  # Ensure the entire generator is unrolled.
  File "/Users/yic/workspace/pants/src/python/pants/engine/legacy/graph.py", line 171, in inject_specs_closure
    for address in self._inject(specs):
  File "/Users/yic/workspace/pants/src/python/pants/engine/legacy/graph.py", line 183, in _inject
    self._index(request.roots)
  File "/Users/yic/workspace/pants/src/python/pants/engine/legacy/graph.py", line 68, in _index
    'Build graph construction failed for {}:\n{}'.format(node.subject, trace))

Exception message: Build graph construction failed for DescendantAddresses(directory='examples/tests'):
  Computing LegacyTarget for DescendantAddresses(directory='examples/tests')
    Computing LegacyTarget for examples/tests/scala/org/pantsbuild/example/hello/welcome:welcome
      Computing LegacyTarget for examples/src/scala/org/pantsbuild/example/hello/welcome:welcome
        Computing LegacyTarget for examples/src/java/org/pantsbuild/example/hello/greet:greet
          Computing TargetAdaptor for examples/src/java/org/pantsbuild/example/hello/greet:greet
            Computing Struct for examples/src/java/org/pantsbuild/example/hello/greet:greet
              Computing UnhydratedStruct for examples/src/java/org/pantsbuild/example/hello/greet:greet
                Computing AddressFamily for Dir(path=u'examples/src/java/org/pantsbuild/example/hello/greet')
                  Throw(exc=MappingError(u"Failed to parse examples/src/java/org/pantsbuild/example/hello/greet/BUILD:\nname 'abc' is not defined",))
    Computing LegacyTarget for examples/tests/java/org/pantsbuild/example/hello/greet:greet
      Throw(exc=MappingError(u"Failed to parse examples/src/java/org/pantsbuild/example/hello/greet/BUILD:\nname 'abc' is not defined",))

Bugs closed: 3535, 3584

Reviewed at https://rbcommons.com/s/twitter/r/3992/

src/python/pants/engine/scheduler.py

@@ -282,16 +282,31 @@ def trace(self, root):
     TODO: This could use polish. In particular, the `__str__` representations of Nodes and
     States are probably not sufficient for user output.
     """
+
     traced = set()
-    def _format(level, node, state):
-      return '{}Computing {} for {}: {}'.format('  ' * level, node.product.__name__, node.subject, state)
+
+    def is_bottom(entry):
+      return type(entry.state) in (Noop, Return) or entry in traced
+
+    def is_one_level_above_bottom(parent_entry):
+      return all(is_bottom(child_entry) for child_entry in parent_entry.dependencies)
+
+    def _format(level, entry, state):
+      output = '{}Computing {} for {}'.format('  ' * level,
+                                              entry.node.product.__name__,
+                                              entry.node.subject)
+      if is_one_level_above_bottom(entry):
+        output += '\n{}{}'.format('  ' * (level + 1), state)
+
+      return output
+
     def _trace(entry, level):
-      if type(entry.state) in (Noop, Return) or entry in traced:
+      if is_bottom(entry):
         return
       traced.add(entry)
-      yield _format(level, entry.node, entry.state)
+      yield _format(level, entry, entry.state)
       for dep in entry.cyclic_dependencies:
-        yield _format(level, entry.node, Noop.cycle(entry.node, dep))
+        yield _format(level, entry, Noop.cycle(entry.node, dep))
       for dep_entry in entry.dependencies:
         for l in _trace(dep_entry, level+1):
           yield l

tests/python/pants_test/engine/test_graph.py

@@ -146,7 +146,7 @@ def address(name):
                                           strict=False,
                                           lang='java')
     public = Struct(address=address('public'),
-                           url='https://oss.sonatype.org/#stagingRepositories')
+                    url='https://oss.sonatype.org/#stagingRepositories')
     thrift1 = Target(address=address('thrift1'))
     thrift2 = Target(address=address('thrift2'), dependencies=[thrift1])
     expected_java1 = Target(address=address('java1'),
@@ -194,36 +194,68 @@ def test_resolve_cache(self):
 
     self.assertEquals(java1, self.resolve(scheduler, java1_address))
 
-  def do_test_cycle(self, scheduler, address_str):
-    walk = self.walk(scheduler, Address.parse(address_str))
+  def do_test_trace_message(self, scheduler, parsed_address, expected_string=None):
+    walk = self.walk(scheduler, parsed_address)
     # Confirm that the root failed, and that a cycle occurred deeper in the graph.
     root, state = walk[0]
     self.assertEqual(type(state), Throw)
-    self.assertTrue(any('cycle' in line for line in scheduler.product_graph.trace(root)))
+    trace_message = '\n'.join(scheduler.product_graph.trace(root))
+
+    self.assert_throws_are_leaves(trace_message, Throw.__name__)
+    if expected_string:
+      self.assertIn(expected_string, trace_message)
+
+  def do_test_cycle(self, address_str):
+    scheduler = self.create_json()
+    parsed_address = Address.parse(address_str)
+    self.do_test_trace_message(scheduler, parsed_address, 'cycle')
+
+  def assert_throws_are_leaves(self, error_msg, throw_name):
+    def indent_of(s):
+      return len(s) - len(s.lstrip())
+
+    def assert_equal_or_more_indentation(more_indented_line, less_indented_line):
+      self.assertTrue(indent_of(more_indented_line) >= indent_of(less_indented_line),
+                      '\n"{}"\nshould have more equal or more indentation than\n"{}"'.format(more_indented_line,
+                                                                                             less_indented_line))
+
+    lines = error_msg.splitlines()
+    line_indices_of_throws = [i for i, v in enumerate(lines) if throw_name in v]
+    for idx in line_indices_of_throws:
+      # Make sure lines with Throw have more or equal indentation than its neighbors.
+      current_line = lines[idx]
+      line_above = lines[max(0, idx - 1)]
+      line_below = lines[min(len(lines) - 1, idx + 1)]
+
+      assert_equal_or_more_indentation(current_line, line_above)
+      assert_equal_or_more_indentation(current_line, line_below)
 
   def test_cycle_self(self):
-    self.do_test_cycle(self.create_json(), 'graph_test:self_cycle')
+    self.do_test_cycle('graph_test:self_cycle')
 
   def test_cycle_direct(self):
-    self.do_test_cycle(self.create_json(), 'graph_test:direct_cycle')
+    self.do_test_cycle('graph_test:direct_cycle')
 
   def test_cycle_indirect(self):
-    self.do_test_cycle(self.create_json(), 'graph_test:indirect_cycle')
+    self.do_test_cycle('graph_test:indirect_cycle')
 
   def test_type_mismatch_error(self):
     scheduler = self.create_json()
     mismatch = Address.parse('graph_test:type_mismatch')
     self.assertEquals(type(self.resolve_failure(scheduler, mismatch)), ResolvedTypeMismatchError)
+    self.do_test_trace_message(scheduler, mismatch)
 
   def test_not_found_but_family_exists(self):
     scheduler = self.create_json()
     dne = Address.parse('graph_test:this_addressable_does_not_exist')
     self.assertEquals(type(self.resolve_failure(scheduler, dne)), ResolveError)
+    self.do_test_trace_message(scheduler, dne)
 
   def test_not_found_and_family_does_not_exist(self):
     scheduler = self.create_json()
     dne = Address.parse('this/dir/does/not/exist')
     self.assertEquals(type(self.resolve_failure(scheduler, dne)), ResolveError)
+    self.do_test_trace_message(scheduler, dne)
 
 
 class LazyResolvingGraphTest(GraphTestBase):
@@ -242,7 +274,7 @@ def address(name):
 
     public_address = address('public')
     expected_public = Struct(address=public_address,
-                                    url='https://oss.sonatype.org/#stagingRepositories')
+                             url='https://oss.sonatype.org/#stagingRepositories')
 
     thrift2_address = address('thrift2')
     expected_java1 = Target(address=java1_address,