Error handling in Lamina Observable

[Andrew Cholakian]

I've noticed that if a callback is missing an error handler terse, hard to debug errors get generated here in the lamina source code: https://github.com/ztellman/lamina/blob/master/src/lamina/core/observable.clj#L45

I'd like to patch it to provide a full stack trace. Any ideas as far as what the idiomatic clojure way to capture a stack-trace to a string is? I assume we'll want to use the logging library, and simply printing the stacktrace to console is unacceptable.

[Zach Tellman]

Running 'lein repl' in the master branch:

user=> (use 'lamina.core)
nil
user=> (def ch (channel))
#'user/ch
user=> (receive-all ch (fn [_] (throw (Exception.))))
true
user=> (enqueue ch 1)
Jan 17, 2012 10:11:23 PM
clojure.contrib.logging$eval165$impl_write_BANG___168 invoke
SEVERE: Error in message callback
java.lang.Exception
at user$eval2403$fn__2404.invoke(NO_SOURCE_FILE:3)
at lamina.core.seq$receive_all$fn__1293$fn__1298$fn__1299.invoke(seq.clj:141)
at lamina.core.observable$observer$reify__319.on_message(observable.clj:43)
at lamina.core.observable.Observable.message(observable.clj:128)
at lamina.core.observable$siphon$fn__607$fn__609.invoke(observable.clj:243)
at lamina.core.observable$observer$reify__319.on_message(observable.clj:43)
at lamina.core.observable.Observable.message(observable.clj:125)
at lamina.core.channel$enqueue.doInvoke(channel.clj:136)
at clojure.lang.RestFn.invoke(RestFn.java:424)
at clojure.lang.Var.invoke(Var.java:369)
at user$eval2407.invoke(NO_SOURCE_FILE:5)
at clojure.lang.Compiler.eval(Compiler.java:5424)
at clojure.lang.Compiler.eval(Compiler.java:5391)
at clojure.core$eval.invoke(core.clj:2382)
at clojure.main$repl$read_eval_print__5624.invoke(main.clj:183)
at clojure.main$repl$fn__5629.invoke(main.clj:204)
at clojure.main$repl.doInvoke(main.clj:204)
at clojure.lang.RestFn.invoke(RestFn.java:513)
at user$eval27$acc__3869__auto____30$fn__32.invoke(NO_SOURCE_FILE:1)
at clojure.lang.AFn.run(AFn.java:24)
at java.lang.Thread.run(Thread.java:680)

This doesn't seem particularly terse to me. There is a genuine design
issue with exceptions in callbacks that the *only* effect they have is
to log the error, which is being addressed in the next release, but
that doesn't seem to be what you're describing. Can you explain
further?

Zach

[Andrew Cholakian]

Thanks for the reply Zach.

Weird, I've tried this with a multitude of different included libs in project.clj, even stripping it down to just aleph-0.2.1-SNAPSHOT and clojure 1.2.1 and clojure 1.3 (tried both separately)

An example of what I see:

(use 'lamina.core) (let [x (channel)] (receive-all x (fn [_] (throw (Exception. "hai")))) (enqueue x "o"))

nil

Jan 17, 2012 10:38:17 PM sun.reflect.NativeMethodAccessorImpl invoke0

SEVERE: Error in message callback #<Exception java.lang.Exception: hai>

true

clojure.core=> 

Any idea why I don't see the rest of the trace?

[Andrew Cholakian]

I just tried creating a brand-new project with 'lein new'. Clojure 1.3.0 + aleph 0.2.1 

Same deal

I'm on OSX Lion with the following JVM: 

java version "1.6.0_29"

Java(TM) SE Runtime Environment (build 1.6.0_29-b11-402-11M3527)

Java HotSpot(TM) 64-Bit Server VM (build 20.4-b02-402, mixed mode)

[Ryan Spangler]

I have seen the same thing for awhile now.   Is it some kind of system wide java or netty setting?  Also on osx.

[Zach Tellman]

Yeah, this is a semi-breaking change from clojure.contrib.logging to
clojure.tools.logging: the expected order of the exception and message
are inverted, so it's just printing (str ex). I need to go through
the various projects and change the arguments around (and add some
message for everything that is just (log/error ex), which has the same
issue), I just haven't gotten to it. Patches welcome, though I
promise it will be done before 0.2.1 hits alpha.

Zach

[Andrew Cholakian]

Hmm, I'm a little confused. I still see it using contrib.logging in master, so shouldn't it still work?

I'd be glad to patch this, just let me know which branch it is that the latest aleph depends on.

[Zach Tellman]

Maybe I'm confused, but you're mentioning 0.2.1-SNAPSHOT, which is not
in master.

[Andrew Cholakian]

Ah, yeah. I'm def confused. 

My question basically is: I'm using aleph-2.1-SNAPSHOT. Which lamina branch should I be editing to fix this logging issue? I'm not sure which branches correspond to which releases on clojars.

[Zach Tellman]

master -> aleph 0.2.0, lamina 0.4.0
clj-1.3 -> aleph 0.2.1, lamina 0.4.1
perf -> lamina 0.5.0 (it's coming along nicely!)

[Andrew Cholakian]

Glad to hear about perf! I'll tackle the 0.4.1 branch of lamina early tomorrow.

[Andrew Cholakian]

Patched, and pull request sent.