Exception reporting

[Timothy Pratley]

If you put the following into a file and run it:

(defn new-listener [port]
(try (java.net.ServerSocket. port)
(println "Listening on " port)
(catch Exception e
(println "Failed to listen on port " port ":
" (.getMessage e)))))

(println "Server started")
(let [listener (new-listener 8888)]
(.accept listener))


Exception in thread "main" java.lang.NullPointerException (test.clj:0)

The problem is obviously my user code: new-listener should have
returned the socket it created. I'm just bringing it up because the
resulting exception doesn't have enough info to diagnose the problem.
Usually when there is an error the it displays the line number where
the problem occurred in the source. Is this a special case? I only
report it in the hope that such reports can help identify improvements
to error reporting.

Regards,
Tim.

[Stuart Sierra]

If you're running this at the REPL, in recent versions only the name
of the exception is printed. If you want the full backtrace, do:
(.printStackTrace *e)

-Stuart Sierra

[Michael Wood]

On Mon, Nov 24, 2008 at 4:45 PM, Stuart Sierra
<the.stua...@gmail.com> wrote:
>
> If you're running this at the REPL, in recent versions only the name
> of the exception is printed. If you want the full backtrace, do:
> (.printStackTrace *e)

That doesn't explain why the line number is listed as 0.

Is that expected?

The stack trace does not appear to be any more helpful anyway:

user=> (let [listener (new-listener 8888)]
(.accept listener))
java.lang.NullPointerException (NO_SOURCE_FILE:0)
user=> (.printStackTrace *e)
java.lang.NullPointerException (NO_SOURCE_FILE:0)
at clojure.lang.Compiler.eval(Compiler.java:4118)
at clojure.lang.Repl.main(Repl.java:93)
Caused by: java.lang.NullPointerException
at clojure.lang.Reflector.invokeNoArgInstanceMember(Reflector.java:253)
at user$eval__40.invoke(Unknown Source)
at clojure.lang.Compiler.eval(Compiler.java:4107)
... 1 more
nil

--
Michael Wood <esio...@gmail.com>

[Chris Turner]

On Nov 24, 7:38 am, "Michael Wood" <esiot...@gmail.com> wrote:
> On Mon, Nov 24, 2008 at 4:45 PM, Stuart Sierra
>

> Michael Wood <esiot...@gmail.com>

The reason the line number is 0 is the NPE happens in the REPL... (new-
listener 8888) is not throwing the exception, it's just returning
null. The NPE happens on the next line: (.accept listener) where
listener is now set to null.

Chris

[Michael Wood]

Hi

On Wed, Nov 26, 2008 at 6:27 AM, Chris Turner <J.Chris...@gmail.com> wrote:
>
> On Nov 24, 7:38 am, "Michael Wood" <esiot...@gmail.com> wrote:
>> On Mon, Nov 24, 2008 at 4:45 PM, Stuart Sierra
>>
>> <the.stuart.sie...@gmail.com> wrote:
>>
>> > If you're running this at the REPL, in recent versions only the name
>> > of the exception is printed. If you want the full backtrace, do:
>> > (.printStackTrace *e)
>>
>> That doesn't explain why the line number is listed as 0.
>>
>> Is that expected?

[...]

> The reason the line number is 0 is the NPE happens in the REPL... (new-
> listener 8888) is not throwing the exception, it's just returning
> null. The NPE happens on the next line: (.accept listener) where
> listener is now set to null.

I still don't see why it's line 0 :) I realise that (new-listener)
has nothing to do with it really and that it is the null pointer
dereference that causes this, but surely it is not on
NO_SOURCE_FILE:0. If this is expected on the REPL for some reason,
then take a look at Timothy's original message in this thread. He was
loading it from test.clj and the exception was reported on test.clj:0.

On a related note, if I try to evaluate a nonexistent symbol at the
REPL it always seems to report it as line 0, whereas if I try to
evaluate a nonexistent function it is reported correctly:

$ clj
Clojure
user=> blah
java.lang.Exception: Unable to resolve symbol: blah in this context
(NO_SOURCE_FILE:0)
user=> blah
java.lang.Exception: Unable to resolve symbol: blah in this context
(NO_SOURCE_FILE:0)
user=> blah
java.lang.Exception: Unable to resolve symbol: blah in this context
(NO_SOURCE_FILE:0)
user=> (blah)
java.lang.Exception: Unable to resolve symbol: blah in this context
(NO_SOURCE_FILE:4)
user=>

This is with r1121.

--
Michael Wood <esio...@gmail.com>

[Timothy Pratley]

I did some more testing on this and discovered some interesting
things...

Executive Summary: I propose the following patch

Index: src/jvm/clojure/lang/Compiler.java
===================================================================
--- src/jvm/clojure/lang/Compiler.java (revision 1123)
+++ src/jvm/clojure/lang/Compiler.java (working copy)
@@ -4115,7 +4115,7 @@
catch(Throwable e)
{
if(!(e instanceof CompilerException))
- throw new CompilerException((String) SOURCE.get
(), (Integer) LINE.get(), e);
+ throw new CompilerException((String) SOURCE.get
(), (Integer) LINE_AFTER.get(), e);
else
throw (CompilerException) e;
}

And would like to query whether a caught exceptions stack trace should
report the catch line number or the exception line number (I would
have thought the latter, but the former is true). If this needs
changing can I get some tips where to look in the code (I can't think
what to search for, seeing 'catch' is everywhere).

I noticed that LINE.get() is called quite a lot in Compiler.java...
but LINE.set() is not called. Is LINE set somewhere else... in core
perhaps, or are those reference to LINE in need of being renamed also?

Rationale:

file test1:
(.accept nil)

file test2:
(try (.accept nil)
(catch Exception e ((println "StackTrace:")(.printStackTrace e)))))

*** Rev 1123 ***
C:\Documents and Settings\Ninja\My Documents\clojure-svn\trunk>clj
test1.clj
Exception in thread "main" java.lang.NullPointerException (test1.clj:
0)
at clojure.lang.Compiler.eval(Compiler.java:4118)
at clojure.lang.Compiler.load(Compiler.java:4434)
at clojure.lang.Compiler.loadFile(Compiler.java:4401)
at clojure.lang.Script.main(Script.java:65)
Caused by: java.lang.NullPointerException
at clojure.lang.Reflector.invokeNoArgInstanceMember
(Reflector.java:253)
at clojure.core$eval__2.invoke(test1.clj:1)
at clojure.lang.Compiler.eval(Compiler.java:4107)
... 3 more

C:\Documents and Settings\Ninja\My Documents\clojure-svn\trunk>clj
test2.clj
StackTrace:
java.lang.NullPointerException
at clojure.lang.Reflector.invokeNoArgInstanceMember
(Reflector.java:253)
at clojure.core$eval__2.invoke(test2.clj:1)
at clojure.lang.Compiler.eval(Compiler.java:4107)
at clojure.lang.Compiler.load(Compiler.java:4434)
at clojure.lang.Compiler.loadFile(Compiler.java:4401)
at clojure.lang.Script.main(Script.java:65)
Exception in thread "main" java.lang.NullPointerException (test2.clj:
0)
at clojure.lang.Compiler.eval(Compiler.java:4118)
at clojure.lang.Compiler.load(Compiler.java:4434)
at clojure.lang.Compiler.loadFile(Compiler.java:4401)
at clojure.lang.Script.main(Script.java:65)
Caused by: java.lang.NullPointerException
at clojure.core$eval__2.invoke(test2.clj:2)
at clojure.lang.Compiler.eval(Compiler.java:4107)
... 3 more



I found the line 0 behavior occurs since rev1031, prior to that it was
reported (though not in the message, only the stack):

*** Rev 1030 ***
C:\Documents and Settings\Ninja\My Documents\clojure-svn\trunk>clj
test1.clj

Exception in thread "main" java.lang.NullPointerException

at clojure.lang.Reflector.invokeNoArgInstanceMember
(Reflector.java:243)
at clojure.eval__2290.invoke(test1.clj:1)
at clojure.lang.Compiler.eval(Compiler.java:3891)
at clojure.lang.Compiler.load(Compiler.java:4196)
at clojure.lang.Compiler.loadFile(Compiler.java:4163)
at clojure.lang.Script.main(Script.java:64)

C:\Documents and Settings\Ninja\My Documents\clojure-svn\trunk>clj
test2.clj
StackTrace:
java.lang.NullPointerException
at clojure.lang.Reflector.invokeNoArgInstanceMember
(Reflector.java:243)
at clojure.eval__2290.invoke(test2.clj:1)
at clojure.lang.Compiler.eval(Compiler.java:3891)
at clojure.lang.Compiler.load(Compiler.java:4196)
at clojure.lang.Compiler.loadFile(Compiler.java:4163)
at clojure.lang.Script.main(Script.java:64)

Exception in thread "main" java.lang.NullPointerException

at clojure.eval__2290.invoke(test2.clj:2)
at clojure.lang.Compiler.eval(Compiler.java:3891)
at clojure.lang.Compiler.load(Compiler.java:4196)
at clojure.lang.Compiler.loadFile(Compiler.java:4163)
at clojure.lang.Script.main(Script.java:64)

However as you can see, caught exceptions still report the catch line.

C:\Documents and Settings\Ninja\My Documents\clojure-svn\trunk>svn log
-r 1030:1031
------------------------------------------------------------------------
r1030 | rhickey | 2008-09-18 10:49:28 +1000 (Thu, 18 Sep 2008) | 1
line

Fixed doc for descendants
------------------------------------------------------------------------
r1031 | rhickey | 2008-09-18 23:17:02 +1000 (Thu, 18 Sep 2008) | 1
line

improved error location info
------------------------------------------------------------------------

[Timothy Pratley]

Hi

> -                       throw new CompilerException((String) SOURCE.get
> (), (Integer) LINE.get(), e);
> +                       throw new CompilerException((String) SOURCE.get
> (), (Integer) LINE_AFTER.get(), e);

Having dug through the code a bit more, I don't my patch suggestion is
quite right.
It happens to work for my test case but if the source expression
spanned multiple lines it would return the last line, which might be
misleading. I'll take another look on the weekend.