Details

Reviewers

Group Reviewers

Maniphest Tasks

T8156: Linter failures don't provide relevant stacktraces

Summary

Fixes T8156. If an aggregate exception is thrown, the stack trace is lost (even when running with --trace). This makes it extremely difficult to troubleshoot custom linters, for example.

Test Plan

Forced a linter to throw an exception and ran arc lint --trace, saw a stack trace.

Diff Detail

Repository

rPHU libphutil

Branch

master

Lint

Lint Passed

Unit

Tests Passed

Build Status

Buildable 5998
Build 6018: [Placeholder Plan] Wait for 30 Seconds

Event Timeline

joshuaspence updated this revision to Diff 30761.May 11 2015, 9:36 PM

joshuaspence retitled this revision from to Provide stacktraces for aggregate exceptions.

joshuaspence updated this object.

joshuaspence edited the test plan for this revision. (Show Details)

joshuaspence added a reviewer: epriestley.

joshuaspence added a task: T8156: Linter failures don't provide relevant stacktraces.

Herald added a reviewer: Blessed Reviewers. · View Herald TranscriptMay 11 2015, 9:37 PM

Herald added subscribers: epriestley, Korvin. · View Herald Transcript

Ideally we could implement PhutilAggregateException::__toStackTrace() to customize this, but that doesn't seem viable.

What makes an approach in this vein hard? Particularly, I would expect PhutilErrorHandler to be able to do this fairly easily somewhere inside handleException(). We already have some related affordances there (getRootException(), getPreviousException(), etc).

I think I briefly attempted that but to no avail... let me try again.

Move to rPHU

joshuaspence updated this object.May 14 2015, 10:55 AM

joshuaspence edited the test plan for this revision. (Show Details)

I'm worried this will spew a lot of confusing / context-free messages into the log. In particular, I'm concerned that users will copy/paste the wrong message when asking for debugging help, and lead me down the wrong path because I have only part of the picture. I'd like to emit one message with all of the information instead of a series of messages which aren't complete.

I believe we can do this by adding more frames to the trace parameter, although this might take some additional tweaking. I'd ideally like the final result to look something like this:

PhutilAggregateException: blah blah aggregate message {>} blah blah specific message
#0 specific trace a.php:23
#1 specific trace b.php:99
...
#7 specific trace z.php:72
#0 aggregate trace y.php:13
#1 aggregate trace x.php:123
...
#7 aggregate trace main.php:6

..maybe with a little more embellishment.

Even better would be printing shared stack frames only once, so, say, #7 through #4 would print once and the unique frames for #3, #2 and #1 would print separately or whatever.

This revision now requires changes to proceed.May 14 2015, 1:31 PM

It gets a little bit messy in the current state of the code...

If you run without --trace, an aggregate exception will look like this:

Exception
Some linters failed:
    - PhutilAggregateException: Something failed!
          - Exception: This is an exception
          - Exception: This is another exception
(Run with `--trace` for a full exception trace.)

If you run with --trace, it will look like this:

[2015-05-14 21:22:05] EXCEPTION: (PhutilAggregateException) Some linters failed:
    - PhutilAggregateException: Something failed!
          - Exception: This is an exception
          - Exception: This is another exception at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:275]
arcanist(head=master, ref.master=e1a051a033b8), phutil(head=master, ref.master=f714e8f8494f)
  #0 ArcanistLintEngine::run() called at [<arcanist>/src/workflow/ArcanistLintWorkflow.php:331]
  #1 ArcanistLintWorkflow::run() called at [<arcanist>/scripts/arcanist.php:387]

The stacktrace at the end is handled by PHP:

catch (Exception $ex) {
  ...

  if ($config_trace_mode) {
    echo "\n";
    throw $ex;
  }

  ...
}

So roughly, I think that the options are as follows:

Always show a stacktrace (even without --trace).
Attempt to trick PHP into showing multiple stacktraces (this was my original point regarding the __toStackTrace() method).
Maybe PhutilErrorHandler aware of --trace mode and avoiding throwing an unhandled exception completely.

This is a slight improvement:

[2015-05-14 21:35:06] EXCEPTION: (PhutilAggregateException) Some linters failed:
    - Exception: This is also an exception
    - Exception: This is an exception at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:275]
arcanist(head=master, ref.master=e1a051a033b8), phutil(head=master, ref.master=f714e8f8494f)
  #0 ArcanistLintEngine::run() called at [<arcanist>/src/workflow/ArcanistLintWorkflow.php:331]
  #1 ArcanistLintWorkflow::run() called at [<arcanist>/scripts/arcanist.php:387]
[2015-05-14 21:35:06] EXCEPTION: (Exception) This is also an exception at [<arcanist>/src/lint/linter/ArcanistTextLinter.php:92]
arcanist(head=master, ref.master=e1a051a033b8), phutil(head=master, ref.master=f714e8f8494f)
  #0 ArcanistTextLinter::lintPath(string) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:585]
  #1 ArcanistLintEngine::executeLinterOnPaths(ArcanistTextLinter, array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:543]
  #2 ArcanistLintEngine::executeLintersOnChunk(array, array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:481]
  #3 ArcanistLintEngine::executeLinters(array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:219]
  #4 ArcanistLintEngine::run() called at [<arcanist>/src/workflow/ArcanistLintWorkflow.php:331]
  #5 ArcanistLintWorkflow::run() called at [<arcanist>/scripts/arcanist.php:387]
[2015-05-14 21:35:06] EXCEPTION: (Exception) This is an exception at [<arcanist>/src/lint/linter/ArcanistXHPASTLinter.php:325]
arcanist(head=master, ref.master=e1a051a033b8), phutil(head=master, ref.master=f714e8f8494f)
  #0 ArcanistXHPASTLinter::resolveFuture(string, ExecFuture) called at [<arcanist>/src/lint/linter/ArcanistFutureLinter.php:34]
  #1 ArcanistFutureLinter::didLintPaths(array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:602]
  #2 ArcanistLintEngine::executeDidLintOnPaths(ArcanistXHPASTLinter, array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:553]
  #3 ArcanistLintEngine::executeLintersOnChunk(array, array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:481]
  #4 ArcanistLintEngine::executeLinters(array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:219]
  #5 ArcanistLintEngine::run() called at [<arcanist>/src/workflow/ArcanistLintWorkflow.php:331]
  #6 ArcanistLintWorkflow::run() called at [<arcanist>/scripts/arcanist.php:387]

Slight improvement maybe?

Implement Iterator interface

Almost works!

@epriestley, is this what you had in mind? (It doesn't work well without --trace at the moment):

[2015-05-14 21:50:27] EXCEPTION: (PhutilAggregateException) Some linters failed: {>} (Exception) This is also an exception {>} (Exception) This is an exception at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:275]
arcanist(head=master, ref.master=e1a051a033b8), phutil(head=master, ref.master=e84c299d864d)
  #0 ArcanistLintEngine::run() called at [<arcanist>/src/workflow/ArcanistLintWorkflow.php:331]
  #1 ArcanistLintWorkflow::run() called at [<arcanist>/scripts/arcanist.php:387]
arcanist(head=master, ref.master=e1a051a033b8), phutil(head=master, ref.master=e84c299d864d)
  #0 ArcanistTextLinter::lintPath(string) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:585]
  #1 ArcanistLintEngine::executeLinterOnPaths(ArcanistTextLinter, array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:543]
  #2 ArcanistLintEngine::executeLintersOnChunk(array, array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:481]
  #3 ArcanistLintEngine::executeLinters(array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:219]
  #4 ArcanistLintEngine::run() called at [<arcanist>/src/workflow/ArcanistLintWorkflow.php:331]
  #5 ArcanistLintWorkflow::run() called at [<arcanist>/scripts/arcanist.php:387]
arcanist(head=master, ref.master=e1a051a033b8), phutil(head=master, ref.master=e84c299d864d)
  #0 ArcanistXHPASTLinter::resolveFuture(string, ExecFuture) called at [<arcanist>/src/lint/linter/ArcanistFutureLinter.php:34]
  #1 ArcanistFutureLinter::didLintPaths(array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:602]
  #2 ArcanistLintEngine::executeDidLintOnPaths(ArcanistXHPASTLinter, array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:553]
  #3 ArcanistLintEngine::executeLintersOnChunk(array, array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:481]
  #4 ArcanistLintEngine::executeLinters(array) called at [<arcanist>/src/lint/engine/ArcanistLintEngine.php:219]
  #5 ArcanistLintEngine::run() called at [<arcanist>/src/workflow/ArcanistLintWorkflow.php:331]
  #6 ArcanistLintWorkflow::run() called at [<arcanist>/scripts/arcanist.php:387]