Bug 272371 - [ErrorHandling] The "Details" on a "Problem Occurred" are not very informative.
Summary: [ErrorHandling] The "Details" on a "Problem Occurred" are not very informative.
Status: VERIFIED FIXED
Alias: None
Product: Platform
Classification: Eclipse Project
Component: UI (show other bugs)
Version: 3.5   Edit
Hardware: Macintosh Mac OS X - Carbon (unsup.)
: P3 normal (vote)
Target Milestone: 3.5 M7   Edit
Assignee: Kevin McGuire CLA
QA Contact: Kevin McGuire CLA
URL:
Whiteboard:
Keywords:
Depends on: 273141
Blocks:
  Show dependency tree
 
Reported: 2009-04-15 15:07 EDT by David Chase CLA
Modified: 2009-05-19 17:38 EDT (History)
5 users (show)

See Also:


Attachments
Shows lack of details when "details" are requested; text could not be copy/pasted (20.47 KB, image/png)
2009-04-15 15:07 EDT, David Chase CLA
no flags Details
Szymon's error log view (68.24 KB, image/jpeg)
2009-04-17 04:23 EDT, Szymon Brandys CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description David Chase CLA 2009-04-15 15:07:11 EDT
Created attachment 131965 [details]
Shows lack of details when "details" are requested; text could not be copy/pasted

Build ID:  I20090313-0100

Steps To Reproduce:
1.Trigger a build failure (I know, you can never find one when you want one)
2.Request to see "Details".
3.Be somewhat amused that someone went to all the trouble to ask me to click a button for the privilege of reading:

And here, you must follow the link, because the error message did not respond to cut-and-paste mouse/keyboard actions 

http://homepage.mac.com/dr2chase/images/EclipseDetailsHah.png

Or you can trust me that the entirety of the additional information in the "details" pane (that does not duplicate the header text), is "assertion failed".  No stack trace, no pointer to a log file, nothing, nada, zilch.  If I filed a bug saying that "assertion failed", you would bounce it for lack of information, but what information could you possibly be talking about, eh?  "assertion failed", end of story.

And of course, it must cause you great embarrassment to ask for more information, knowing that Eclipse had the info, but went and hid it from me, even when I asked to see "Details".  I would not want Eclipse developers to be unduly embarrassed, which is why I reported this bug.

(The failure to copy text bug has been filed and enhanced separately, see https://bugs.eclipse.org/bugs/show_bug.cgi?id=272316 )

More information:
I was running 3.5M6, Eclipse Classic, Cocoa, on a Mac, 10.5.6, plus Scala nightly and Subclipse plugins.  The build failure was a bit of a surprise.

It is possible that the uninformativeness of this message is specific to some plugin, but since the "details" do not identify the plugin (since the Eclipse plugin Architecture, if this is true, allowed the plugin to hide its identity), it remains an Eclipse problem.
Comment 1 Paul Webster CLA 2009-04-16 09:31:52 EDT
If there's anything in your error log, please attach it ... <workspace>/.metadata/.log.  That is the record of any true errors.

If it is another plugin not reporting anything more than a failure (and not filling in its plugin ID), there's not much we can do about it.  If it is reporting more information, we should be able to find it (and if we're not, then fix it).

Kevin, we should allow copying at the very least from all our dialogs, no?

PW
Comment 2 David Chase CLA 2009-04-16 10:46:42 EDT
I think I need to explain -- this is a UI problem, in that the so-called "Details" are awesomely, almost insultingly uninformative.  I'm not even going to bother reporting that the build failed.  Last time I reported a non-UI bug (a crash after update), the amount of nonsense I had to go through to get the data to report the bug, annoyed me so much, and compelled me to put so many snarky editorial remarks in the bug filing, that I offended some thin-skinned member of the Eclipse team, and he preemptively closed the bug with "WORKSFORME" and a link to a "how to file bugs site", which I thought showed an astonishing lack of self-awareness, given that it was Eclipse itself that was failing to provide the necessary information.

Thus, I decided that the failure to provide information necessary to report a bug, was itself, a bug.  I know myself, if I use a product with uninformative dialogs with text that cannot even be selected so I can insert it into a bug report, I'm going to get really, really snarky, and then I feel all guilty (hah!) for giving those hardworking Eclipse developers the vapors.

Comment 3 Paul Webster CLA 2009-04-16 11:00:20 EDT
(In reply to comment #2)
> I think I need to explain -- this is a UI problem, in that the so-called
> "Details" are awesomely, almost insultingly uninformative.  I'm not even going
> to bother reporting that the build failed.

Yes, we interested in the UI error reporting (not so much the build failure) ... but we need any errors in your error log to target the part that is not working correctly

> member of the Eclipse team, and he preemptively closed the bug with
> "WORKSFORME" and a link to a "how to file bugs site",

Since you asked so nicely, http://www.chiark.greenend.org.uk/~sgtatham/bugs.html

> Thus, I decided that the failure to provide information necessary to report a
> bug, was itself, a bug.

Yes, that is what we need to look at (since we did not cause your build failure)

PW
Comment 4 David Chase CLA 2009-04-16 11:09:13 EDT
What timezone is used for the timestamps in the logfile?  Zulu, or local?  It does not specify -- I am trying to look for the section of the 11000 line logfile that corresponds to just before I filed the bug.

(Or I could attach all 11000 lines....)

Comment 5 David Chase CLA 2009-04-16 11:13:14 EDT
Got it:

!SESSION 2009-04-15 14:38:04.712 -----------------------------------------------
eclipse.buildId=I20090313-0100
java.version=1.5.0_16
java.vendor=Apple Inc.
BootLoader constants: OS=macosx, ARCH=x86, WS=cocoa, NL=en_US
Framework arguments:  -keyring /Users/dr2chase/.eclipse_keyring -showlocation
Command-line arguments:  -os macosx -ws cocoa -arch x86 -keyring /Users/dr2chase/.eclipse_keyring -consoleLog -showlocation

!ENTRY org.eclipse.update.configurator 4 0 2009-04-15 14:38:07.563
!MESSAGE Unable to find feature.xml in directory: /Applications/eclipse-3.5M6/features/org.eclipse.equinox.p2.user.ui_1.1.0.v20090212-7Y2FUGFS4vz-1Fz0P7pTB7KU

!ENTRY org.eclipse.core.jobs 4 2 2009-04-15 14:38:24.089
!MESSAGE An internal error occurred during: "Building workspace".
!STACK 0
java.lang.AssertionError: assertion failed
	at scala.Predef$.assert(Predef.scala:87)
	at scala.tools.eclipse.ScalaPlugin$Project.lampionToNSC(ScalaPlugin.scala:1074)
	at scala.tools.eclipse.ScalaPlugin$Project$$anonfun$build$1.apply(ScalaPlugin.scala:1087)
	at scala.tools.eclipse.ScalaPlugin$Project$$anonfun$build$1.apply(ScalaPlugin.scala:1086)
	at scala.Iterator$class.foreach(Iterator.scala:427)
	at scala.collection.jcl.MutableIterator$Wrapper.foreach(MutableIterator.scala:14)
	at scala.Iterable$class.foreach(Iterable.scala:256)
	at scala.collection.jcl.LinkedHashSet.foreach(LinkedHashSet.scala:18)
	at scala.tools.eclipse.ScalaPlugin$Project.build(ScalaPlugin.scala:1086)
	at scala.tools.eclipse.Builder.build(Builder.scala:111)
	at org.eclipse.core.internal.events.BuildManager$2.run(BuildManager.java:633)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37)
	at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:170)
	at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:201)
	at org.eclipse.core.internal.events.BuildManager$1.run(BuildManager.java:253)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37)
	at org.eclipse.core.internal.events.BuildManager.basicBuild(BuildManager.java:256)
	at org.eclipse.core.internal.events.BuildManager.basicBuildLoop(BuildManager.java:309)
	at org.eclipse.core.internal.events.BuildManager.build(BuildManager.java:341)
	at org.eclipse.core.internal.events.AutoBuildJob.doBuild(AutoBuildJob.java:140)
	at org.eclipse.core.internal.events.AutoBuildJob.run(AutoBuildJob.java:238)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)


Comment 6 Paul Webster CLA 2009-04-16 12:24:10 EDT
(In reply to comment #5)
> Got it:
> 

Thanx, we can work with that.

PW
Comment 7 Kevin McGuire CLA 2009-04-16 18:12:02 EDT
(In reply to comment #1)
> If there's anything in your error log, please attach it ...
> <workspace>/.metadata/.log.  That is the record of any true errors.
> 
> If it is another plugin not reporting anything more than a failure (and not
> filling in its plugin ID), there's not much we can do about it.  If it is
> reporting more information, we should be able to find it (and if we're not,
> then fix it).
> 
> Kevin, we should allow copying at the very least from all our dialogs, no?

I was sure we had a bug for that but couldn't find it so opened bug #272521.

As for the details, the dialog just shows the status' accumulated so we need to figure out what that status should say. 

The starting point is I believe GlobalBuildAction.doBuildOperation, which creates a multi status and accumulates all it encounters while invoking the build.  It only catches CoreExceptions, which java.lang.AssertionError isn't, so someone is wrapping it.

In any case I'm guessing that detailtMessage for the java.lang.AssertionError is set to "assertion failed" (that'd be Scala's bug in not being more specific). I installed the Scala plugin and there's no source for that code so that's as far as I can go with that.

It's probably worth considering whether we should be catching the errors for each builder so that we can identify which builder caused the error.

Other then that, I'm not sure how much more we can say in the details.  Because it's a multistatus, I believe each only gets a single line of details. We couldn't show the stack trace because of that, and even if we could we generally avoid displaying them to the user so since it's often not appropriate for different RCP scenarios.  We could suggest checking the .log.
Comment 8 Kevin McGuire CLA 2009-04-16 18:44:32 EDT
(In reply to comment #7)
> It's probably worth considering whether we should be catching the errors for
> each builder so that we can identify which builder caused the error.

Digging further, it looks like we could create another inner multistatus for each project, which would allow us to identify the offending builder. I'm looking at BuildManager.basicBuildLoop which loops per project looking up the builder.
IncrementalProjectBuilder->ICommand->getBuilderName() would give us the name.
The status could identify the project and the builder.

Moving to core for comment.
Comment 9 Szymon Brandys CLA 2009-04-17 04:23:15 EDT
Created attachment 132186 [details]
Szymon's error log view

I tried to reproduce it on Windows XP using I20090407-1430 and Mac using N20090407 cocoa version. To reproduce the issue I added a faulty custom builder always throwing assertion. First thing is that when auto build fails, I can't see the dialog. 

I looked in the code to verify what is logged in such a case and all details Kevin mentioned are logged when a builder fails. I'm attaching my error log view, to show what is logged.

The names of project and builder that fail is logged too.
Comment 10 Szymon Brandys CLA 2009-04-17 04:31:30 EDT
All the details are provided. You could also look at BuildManager#getSafeRunnable. ISafeRunnable provided by this method creates the status containing project and builder names, when fails.

I'm guessing that statuses in the dialog (attached in comment 0) contain all the details, however they would have to be expanded to show inner statuses probably.

Moving back to UI.
Comment 11 Kevin McGuire CLA 2009-04-17 12:32:23 EDT
(In reply to comment #9)
> Created an attachment (id=132186) [details]
> Szymon's error log view
> 
> First thing is that when auto build fails, I can't
> see the dialog. 

This is different, the reporter gets a status dialog.  I'm not sure how, since the stack trace matches the manual test you sent me Szymon (ie. the "normal" behaviour is to not show the error dialog).

@David, are there additional steps you can provide?  Even if I run a manual build I don't get the dialog.

In any case, not reporting errors from builds seems bad. You have a build failure and don't know there's a problem unless you happen to have the error log view open.  I've opened bug #272726 for that.

Now that I can produce the error dialog I will look at better displaying the information we have.

Btw. the status dialog I am now seeing DOES have a Copy menu in the details. It's not quite the same dialog either.  Will investigate.
Comment 12 David Chase CLA 2009-04-17 13:29:36 EDT
I'm not quite sure what you're after here.

The build failure for me is not itself reproducible on command; I've just had a very buggy week, and been impeded in the simple filing of bugs by dialogs that lack information, and "text" that (on a Mac, important detail I think) cannot be selected.

I first rolled every complaint about every impediment to filing a bug, into the first bug that I submitted.  That didn't work well.

So I am instead filing each individual problem, as I encounter it, when I encounter it.  The bug here is that, if I get a build failure (maybe that, particular, anonymous build failure), that it is uninformative; that it is anonymous; that the text (on a Mac) cannot be copied out, even if it were informative.  The workaround, for a bug that I care about, is to go digging in the .metadata/.log file, but if that's the case, why waste time with a button and uncopyable uninformative text?  The whole point of a good UI is that time is not spent on workarounds.

Comment 13 Kevin McGuire CLA 2009-04-17 17:41:23 EDT
(In reply to comment #12)
> I'm not quite sure what you're after here.

I was trying to see if you were say just auto build on, doing manual builds, etc., since I wasn't seeing the same results.  Thanks for the response but I see the problem now - it's Scala's throwing of java.lang.AssertionError which is in a much different hierarchy in Error than our assertions, thus caught differently and producing different results.
Comment 14 Kevin McGuire CLA 2009-04-17 19:14:10 EDT
The java.lang.Assertion error isn't being caught until Worker.run() catching of Error.  By then, we no longer know it's a build (and the multistatus that we were creating as part of the build is now gone).  So the error being reported is a Job error, not a more specific build error.  All we have is the job name "Building workspace".  Thus, no good information to report.

We should instead (carefully) catch Error in the builder or the SafeRunnable we create.
Comment 15 Szymon Brandys CLA 2009-04-18 07:45:29 EDT
(In reply to comment #14)
> We should instead (carefully) catch Error in the builder or the SafeRunnable we
> create.

One more way is to extend the set of errors being caught in SafeRunner. So far these are only Exceptions and LinkageError.

I think that Scala should throw more informative exception or error. So far even if we caught the assertion in BuildManager, we would have nothing more to report than the builder class (which is already included in the stack trace) and the project name. I would suggest to use org.eclipse.core.runtime.Assert in builders.

Comment 16 Kevin McGuire CLA 2009-04-18 19:54:50 EDT
(In reply to comment #15)
> One more way is to extend the set of errors being caught in SafeRunner. So far
> these are only Exceptions and LinkageError.

Yes I was experimenting with that approach on Friday.  Going from memory, I seem to recall that BuildManager was the better spot since we got the error properly wrapped in the multistatus pre-configured with the build info.
I think SafeRunner gives us the:
 Problems occured when invoking code from plug-in: "org.eclipse.core.resources"

which is both superfluous and misleading (it suggests it was a core resource error but it wasn't, it was just the core.resource build infrastucture triggering the work).

> I think that Scala should throw more informative exception or error. 

Yes.  But the problem is that the Scala error, being subtype of Error, is caught way down in Worker where we no longer know the context of it being in the build.  That kind of pattern I think we should fix since not only core exceptions happen in builds.

> So far
> even if we caught the assertion in BuildManager, we would have nothing more to
> report than the builder class (which is already included in the stack trace)
> and the project name. 

Some comments:

1) At present the scala error is reported way down in Worker, outside the context of the build.  So catching it BuildManager (or somewhere where we have the multistatus from the build) would provide some helpful info.  If you look at the snapshot in the start of the report, there's nothing to go on.  Knowing it was in a build, which builder, which project etc. is I think all we can do and more than we get now.

2) I think we need to look at how we build up the multistatus.  Right now it looks like:

  - Errors during build
  -- badness error occured
  -- Errors running builder X on project Y
  -- Problems occured when invoking code from plug-in: "org.eclipse.core.resources"

Instead it should look like:

  - Errors during build
  -- Errors running builder X on project Y
  --- badness error occured

So one problem is that we create the "Errors running builder..." status *after* we found out there was an error, but as a sibling status to the error status. That's confusing.  Instead, we should create one as a mutlistatus for every builder invocation and pass that in.  That way, caught errors will be created under the more specific error.  We can always remove that inner mutlistatus if empty when we return successfully from the build. 

> I would suggest to use org.eclipse.core.runtime.Assert in builders.

Yes agree and it would've resulted in better info (like your screen shot) but I look at this as a good edge case which we weren't handling: who know what crazy stuff will get run in a builder!

So in *summary*, I think we should:

1) Ensure that build errors result in a Status dialog informing the user. This prevents "Uh, why isn't anything working?" head scratching, or "Hey I found this in the log, no idea what I was doing at the time".

2) Catch Error in the BuildManager or somewhere on that invocation chain where we have the MultiStatus. We probably don't want to catch the really fatal subclasses like ThreadDeath and VirtualMachineError (which includes OOME) since if we're dying then trying to open a dialog will make things worse.

3) Create an inner multistatus for every builder invocation so that errors occuring in that build are its children and thus get properly attributed.  Maybe delete the multistatus if we return and it's empty since otherwise sibling builders producing errors could result in a confusing tree of multistatuses.

4) See if we can get rid of the extra
  Problems occured when invoking code from plug-in: "org.eclipse.core.resources"
Comment 17 John Arthorne CLA 2009-04-21 17:32:05 EDT
>One more way is to extend the set of errors being caught in SafeRunner. So far
>these are only Exceptions and LinkageError.

I have entered bug 273141 for handling AssertionError in SafeRunner. Unlike most other Errors, this is a programming problem similar to IllegalArgumentException and IllegalStateException that I think SafeRunner should be handling.

I'm less sure about handling more general errors deep in the BuildManager code. The specified definition of java.lang.Error is "indicates serious problems that a reasonable application should not try to catch" (from class javadoc on Error). Code that is throwing such a throwable doesn't want it to be caught and ignored (logged, etc). The only reason this is reasonable in the Worker class is that it catches the errors immediately before the thread dies, at which point the error would be lost anyway.
Comment 18 John Arthorne CLA 2009-04-21 18:13:37 EDT
While investigating this, I found that the BuildManager reports build problems with severity of WARNING, and warnings are not surfaced in the UI at all. I'll leave it to the UI team to decide if this makes sense, but in the meantime I'll change the severity of build problems to ERROR to make sure they surface (bug 273147).

It also occurred to me that the button linking to the error log view is not sufficiently obvious. In the first screenshot on this bug, there is a little button that, when clicked, will open the error log view. From the log view individual errors can be viewed/copied/pasted, or the entire log file can be exported to a location of the user's choosing.  This would have led immediately to the stack in comment #5 and this bug might not have been entered. This button should probably be a hyperlink with text, both for usability and for accessibility reasons.
Comment 19 David Chase CLA 2009-04-21 20:17:37 EDT
>In the first screenshot on this bug, there is a little button that, when clicked, will open the error log view.

Do you mean the white X on the red stop sign on the little piece of paper with the lower right corner bent up, appearing near the left side and vertical center?  Yes, I had no idea that did anything at all; I think it would be great if that were a little linkish-thing saying "stack trace" or "error log", or even "gory details".
Comment 20 Kevin McGuire CLA 2009-04-21 22:12:26 EDT
(In reply to comment #17)
> >One more way is to extend the set of errors being caught in SafeRunner. So far
> >these are only Exceptions and LinkageError.
> 
> I have entered bug 273141 for handling AssertionError in SafeRunner. Unlike
> most other Errors, this is a programming problem similar to
> IllegalArgumentException and IllegalStateException that I think SafeRunner
> should be handling.

Thanks.

> I'm less sure about handling more general errors deep in the BuildManager code.
> The specified definition of java.lang.Error is "indicates serious problems that
> a reasonable application should not try to catch" (from class javadoc on
> Error). Code that is throwing such a throwable doesn't want it to be caught and
> ignored (logged, etc). The only reason this is reasonable in the Worker class
> is that it catches the errors immediately before the thread dies, at which
> point the error would be lost anyway.

OK agree. 

(In reply to comment #18)
> While investigating this, I found that the BuildManager reports build problems
> with severity of WARNING, and warnings are not surfaced in the UI at all. I'll
> leave it to the UI team to decide if this makes sense, but in the meantime I'll
> change the severity of build problems to ERROR to make sure they surface (bug
> 273147).

Thanks yes saw the warning and wondered if changing to error would be the simple change needed to surface it in the dialog.

Personally I believe this is the right choice.  They're errors "I couldn't make your stuff man!" not warnings "Oh by the way those classes you thought you had?  You don't".

> It also occurred to me that the button linking to the error log view is not
> sufficiently obvious. 

Wow, apparently I 'own' this area and I didn't know that's what it did (or I forgot).  Yes we need to make it more obvious. Logged bug #273168.

Comment 21 Kevin McGuire CLA 2009-04-21 22:36:18 EDT
I've added bug #273141 and bug #273147 as blocking this one.  When they are fixed I believe we can close this bug.
Comment 22 John Arthorne CLA 2009-04-22 11:00:14 EDT
Agree. Making the two core changes, and improving the link presentation in bug 273168, I believe would address this defect.
Comment 23 Kevin McGuire CLA 2009-05-08 14:59:51 EDT
Bug #273147, which this bug has a blocking, has fixed the issues relevant/blocking this bug.  It remains open because we didn't make the change for build problems to be status type error (currently warning).  However, that aspect is unrelated to this bug.

Therefore closing this bug and removing dependency.  This was closed in M7.

Please open new bugs if there are aspects you believe we can continue to improve.
Comment 24 Paul Webster CLA 2009-05-15 08:39:24 EDT
To assign
Comment 25 Paul Webster CLA 2009-05-15 08:40:12 EDT
assigned
Comment 26 Kevin McGuire CLA 2009-05-19 17:38:35 EDT
Verified in RC1 that:

1) For neither java.lang.AssertionError nor Assert we bring up a status dialog
2) That the corresponding error information in the log is more meaningful in both cases, looks like:

  Errors occurred during build
    Errors running builder <B> on project <P>
  Problems occurred when invoking code from plugin: org.eclipse.core.resources

However, we no longer show the actual triggering error (in this case, assertion error) as a top level item in the log and I think that makes it hard for the user to understand what's going on.

I've logged bug #277013 for this aspect.

Note that the structure in the log is the same we'll get should we decide to report build errors in the status dialog.