Printing a stack trace should show details for the "cause" Exceptions too #317

peterlindstrom123 · 2020-09-11T12:36:19Z

The following neatly formatted stack trace printed by Timbre shows no trace of my own code, which makes it useless for figuring out where an error is happening.

                                          java.lang.Thread.run              Thread.java:  834
            java.util.concurrent.ThreadPoolExecutor$Worker.run  ThreadPoolExecutor.java:  628
             java.util.concurrent.ThreadPoolExecutor.runWorker  ThreadPoolExecutor.java: 1128
       jdk.internal.net.http.Http1Exchange.lambda$cancelImpl$9       Http1Exchange.java:  473
  java.util.concurrent.CompletableFuture.completeExceptionally   CompletableFuture.java: 2088
           java.util.concurrent.CompletableFuture.postComplete   CompletableFuture.java:  506
      java.util.concurrent.CompletableFuture$UniHandle.tryFire   CompletableFuture.java:  907
              java.util.concurrent.CompletableFuture.uniHandle   CompletableFuture.java:  930
jdk.internal.net.http.MultiExchange.lambda$responseAsyncImpl$7       MultiExchange.java:  339
          jdk.internal.net.http.MultiExchange.getExceptionalCF       MultiExchange.java:  412
        jdk.internal.net.http.MultiExchange.toTimeoutException       MultiExchange.java:  463
                java.net.ConnectException: HTTP connect timed out
java.net.http.HttpConnectTimeoutException: HTTP connect timed out
java.net.http.HttpConnectTimeoutException: HTTP connect timed out

But when I call a normal Java .printStackTrace, I see my own code in the details for one of the java.net.http.HttpConnectTimeoutExceptions

The text was updated successfully, but these errors were encountered:

ptaoussanis · 2020-09-12T15:53:18Z

@peterlindstrom123 Hi there!

Could you please try provide a minimum reproducible example?

With the default config in v4.10.0 I'm seeing causes displayed as expected:

(timbre/error (ex-info "Ex.1" {} (ex-info "Ex.2" {} (ex-info "Ex.3" {}))) "Foo") ; =>

Sep 12 15:49 Schrebermann.local ERROR [taoensso.timbre:804] - Foo
nrepl.middleware.interruptible-eval/evaluate/fn  interruptible_eval.clj:   91
                              clojure.core/eval                core.clj: 3214
                                            ...                              
                      taoensso.timbre/eval14635               REPL Input     
                          taoensso.timbre/-log!              timbre.clj:  358
                             clojure.core/deref                core.clj: 2320
                                            ...                              
                   taoensso.timbre/eval14635/fn               REPL Input     
clojure.lang.ExceptionInfo: Ex.3
clojure.lang.ExceptionInfo: Ex.2
clojure.lang.ExceptionInfo: Ex.1

Thanks!

peterlindstrom123 · 2020-09-13T12:47:32Z

Hi,

I'm not sure what you mean.

Is all of this output related to Ex.3?

nrepl.middleware.interruptible-eval/evaluate/fn  interruptible_eval.clj:   91
                              clojure.core/eval                core.clj: 3214
                                            ...                              
                      taoensso.timbre/eval14635               REPL Input     
                          taoensso.timbre/-log!              timbre.clj:  358
                             clojure.core/deref                core.clj: 2320
                                            ...                              
                   taoensso.timbre/eval14635/fn               REPL Input

?

If that's correct, then as far as I can tell, my problem was that no source files or line numbers are mentioned for Ex.2 or Ex.1. A normal Java stack trace would show them all.

Obviously the details for all of the source exceptions are relevant?

lnostdal · 2021-08-18T07:33:23Z

Yeah, hiding the chain of traces is a big mistake. I believe https://github.com/AvisoNovate/pretty is the culprit really. To deal with this I had to create my own :output-fn which basically uses clojure.stacktrace/print-cause-trace.

ptaoussanis · 2022-03-22T17:21:14Z

Just to follow-up on this- I'm still not completely clear on what's being requested here.

It'd be helpful to have the following:

An example that I can run at the REPL
What output you're seeing
What output you'd rather see

Thanks!

lnostdal · 2022-03-23T06:10:30Z

Of course this is pointless here in this example, but in other cases the exception and the cause traces are both actually needed. Compare:

user> (clojure.stacktrace/print-cause-trace (Exception. "hi" (Exception. "cause")))                                                                                                                                                                                                         
java.lang.Exception: hi                                                                                                                                                                                                                                                                     
 at user$eval11357.invokeStatic (NO_SOURCE_FILE:1)                                                                                                                                                                                                                                          
    user$eval11357.invoke (NO_SOURCE_FILE:1)                                                                                                                                                                                                                                                
    clojure.lang.Compiler.eval (Compiler.java:7194)                                                                                                                                                                                                                                         
    clojure.lang.Compiler.eval (Compiler.java:7149)                                                                                                                                                                                                                                         
    clojure.core$eval.invokeStatic (core.clj:3215)                                                                                                                                                                                                                                          
    clojure.core$eval.invoke (core.clj:3211)                                                                                                                                                                                                                                                
    nrepl.middleware.interruptible_eval$evaluate$fn__1245$fn__1246.invoke (interruptible_eval.clj:87)                                                                                                                                                                                       
    clojure.lang.AFn.applyToHelper (AFn.java:152)                                                                                                                                                                                                                                           
    clojure.lang.AFn.applyTo (AFn.java:144)                                                                                                                                                                                                                                                 
    clojure.core$apply.invokeStatic (core.clj:667)                                                                                                                                                                                                                                          
    clojure.core$with_bindings_STAR_.invokeStatic (core.clj:1990)                                                                                                                                                                                                                           
    clojure.core$with_bindings_STAR_.doInvoke (core.clj:1990)                                                                                                                                                                                                                               
    clojure.lang.RestFn.invoke (RestFn.java:425)                                                                                                                                                                                                                                            
    nrepl.middleware.interruptible_eval$evaluate$fn__1245.invoke (interruptible_eval.clj:87)                                                                                                                                                                                                
    clojure.main$repl$read_eval_print__9206$fn__9209.invoke (main.clj:437)                                                                                                                                                                                                                  
    clojure.main$repl$read_eval_print__9206.invoke (main.clj:437)                                                                                                                                                                                                                           
    clojure.main$repl$fn__9215.invoke (main.clj:458)                                                                                                                                                                                                                                        
    clojure.main$repl.invokeStatic (main.clj:458)                                                                                                                                                                                                                                           
    clojure.main$repl.doInvoke (main.clj:368)                                                                                                                                                                                                                                               
    clojure.lang.RestFn.invoke (RestFn.java:1523)                                                                                                                                                                                                                                           
    nrepl.middleware.interruptible_eval$evaluate.invokeStatic (interruptible_eval.clj:84)                                                                                                                                                                                                   
    nrepl.middleware.interruptible_eval$evaluate.invoke (interruptible_eval.clj:56)                                                                                                                                                                                                         
    nrepl.middleware.interruptible_eval$interruptible_eval$fn__1278$fn__1282.invoke (interruptible_eval.clj:152)                                                                                                                                                                            
    clojure.lang.AFn.run (AFn.java:22)                                                                                                                                                                                                                                                      
    nrepl.middleware.session$session_exec$main_loop__1348$fn__1352.invoke (session.clj:218)                                                                                                                                                                                                 
    nrepl.middleware.session$session_exec$main_loop__1348.invoke (session.clj:217)                                                                                                                                                                                                          
    clojure.lang.AFn.run (AFn.java:22)                                                                                                                                                                                                                                                      
    java.lang.Thread.run (Thread.java:833)                                                                                                                                                                                                                                                  
Caused by: java.lang.Exception: cause                                                                                                                                                                                                                                                       
 at user$eval11357.invokeStatic (NO_SOURCE_FILE:1)                                                                                                                                                                                                                                          
    user$eval11357.invoke (NO_SOURCE_FILE:1)                                                                                                                                                                                                                                                
    clojure.lang.Compiler.eval (Compiler.java:7194)                                                                                                                                                                                                                                         
    clojure.lang.Compiler.eval (Compiler.java:7149)                                                                                                                                                                                                                                         
    clojure.core$eval.invokeStatic (core.clj:3215)                                                                                                                                                                                                                                          
    clojure.core$eval.invoke (core.clj:3211)                                                                                                                                                                                                                                                
    nrepl.middleware.interruptible_eval$evaluate$fn__1245$fn__1246.invoke (interruptible_eval.clj:87)                                                                                                                                                                                       
    clojure.lang.AFn.applyToHelper (AFn.java:152)                                                                                                                                                                                                                                           
    clojure.lang.AFn.applyTo (AFn.java:144)                                                                                                                                                                                                                                                 
    clojure.core$apply.invokeStatic (core.clj:667)                                                                                                                                                                                                                                          
    clojure.core$with_bindings_STAR_.invokeStatic (core.clj:1990)                                                                                                                                                                                                                           
    clojure.core$with_bindings_STAR_.doInvoke (core.clj:1990)                                                                                                                                                                                                                               
    clojure.lang.RestFn.invoke (RestFn.java:425)                                                                                                                                                                                                                                            
    nrepl.middleware.interruptible_eval$evaluate$fn__1245.invoke (interruptible_eval.clj:87)                                                                                                                                                                                                
    clojure.main$repl$read_eval_print__9206$fn__9209.invoke (main.clj:437)                                                                                                                                                                                                                  
    clojure.main$repl$read_eval_print__9206.invoke (main.clj:437)                                                                                                                                                                                                                           
    clojure.main$repl$fn__9215.invoke (main.clj:458)                                                                                                                                                                                                                                        
    clojure.main$repl.invokeStatic (main.clj:458)                                                                                                                                                                                                                                           
    clojure.main$repl.doInvoke (main.clj:368)                                                                                                                                                                                                                                               
    clojure.lang.RestFn.invoke (RestFn.java:1523)                                                                                                                                                                                                                                           
    nrepl.middleware.interruptible_eval$evaluate.invokeStatic (interruptible_eval.clj:84)                                                                                                                                                                                                   
    nrepl.middleware.interruptible_eval$evaluate.invoke (interruptible_eval.clj:56)                                                                                                                                                                                                         
    nrepl.middleware.interruptible_eval$interruptible_eval$fn__1278$fn__1282.invoke (interruptible_eval.clj:152)                                                                                                                                                                            
    clojure.lang.AFn.run (AFn.java:22)                                                                                                                                                                                                                                                      
    nrepl.middleware.session$session_exec$main_loop__1348$fn__1352.invoke (session.clj:218)                                                                                                                                                                                                 
    nrepl.middleware.session$session_exec$main_loop__1348.invoke (session.clj:217)                                                                                                                                                                                                          
    clojure.lang.AFn.run (AFn.java:22)                                                                                                                                                                                                                                                      
    java.lang.Thread.run (Thread.java:833)

i.e. both traces vs.

2022-03-23T05:54:54.850Z bullseyeclub-5006 DEBUG [user:61] -                                                                                                                                                                                                                                
   nrepl.middleware.interruptible-eval/evaluate/fn  interruptible_eval.clj:   87                                                                                                                                                                                                            
                                               ...                                                                                                                                                                                                                                          
                       clojure.core/with-bindings*                core.clj: 1990 (repeats 2 times)                                                                                                                                                                                          
                                clojure.core/apply                core.clj:  667                                                                                                                                                                                                            
                                               ...                                                                                                                                                                                                                                          
nrepl.middleware.interruptible-eval/evaluate/fn/fn  interruptible_eval.clj:   87                                                                                                                                                                                                            
                                 clojure.core/eval                core.clj: 3215                                                                                                                                                                                                            
                                               ...                                                                                                                                                                                                                                          
                             user$eval11359.invoke          NO_SOURCE_FILE:   61                                                                                                                                                                                                            
                       user$eval11359.invokeStatic          NO_SOURCE_FILE:   61                                                                                                                                                                                                            
                             taoensso.timbre/-log!             timbre.cljc:  534                                                                                                                                                                                                            
                                clojure.core/deref                core.clj: 2337                                                                                                                                                                                                            
                                               ...                                                                                                                                                                                                                                          
                   user$eval11359$fn__11360.invoke          NO_SOURCE_FILE:   61                                                                                                                                                                                                            
java.lang.Exception: cause                                                                                                                                                                                                                                                                  
java.lang.Exception: hi

..which has only one of the traces.

ptaoussanis · 2022-10-18T16:33:31Z

@lnostdal Hi Lars, thanks for the clear example! Apologies for the delay replying.
This does indeed appear to be the current behaviour of https://github.com/AvisoNovate/pretty.

A couple possibilities:

[Immediate workaround] alter-var-root could be used to change the default stacktrace fn.
[Future Timbre version] default-output-fn could be given an option to specify a different/custom stacktrace fn.

How does (2) sound? Would also be open to ideas re: alternative stracktrace implementations!

Cheers :-)

lnostdal · 2022-10-18T18:05:45Z

Hi there! I'm doing something similar to nr. 1 now - but nr. 2 seems like a better idea.

I don't know about alternatives to the pretty printing done by aviso, but this stacktrace stuff was so important to me I wanted all the details and even noise no matter what - so I just ended up doing: (with-out-str (clojure.stacktrace/print-cause-trace err))

ptaoussanis · 2022-10-19T08:27:20Z

Great, thanks for the feedback @lnostdal.

@lnostdal @peterlindstrom123 An :error-output-fn option will be added to default-output-fn in a forthcoming release. This'll allow one to easily swap in an alternative stacktrace implementation 👍

This makes it easier to provide an alternative stacktrace implementation, etc.

ptaoussanis added the question/usage label Sep 12, 2020

ptaoussanis added ideas welcome enhancement and removed question/usage labels Oct 18, 2022

ptaoussanis added this to the v6 milestone Oct 18, 2022

ptaoussanis self-assigned this Oct 18, 2022

ptaoussanis closed this as completed Oct 19, 2022

ptaoussanis added a commit that referenced this issue Oct 19, 2022

[new] [#317] Add :error-output-fn option to default-output-fn

d84880b

This makes it easier to provide an alternative stacktrace implementation, etc.

ptaoussanis added a commit that referenced this issue Oct 19, 2022

[new] [#317] Add :error-output-fn option to default-output-fn

26c2fdb

This makes it easier to provide an alternative stacktrace implementation, etc.

ptaoussanis added a commit that referenced this issue Oct 20, 2022

[new] [#317] Add :output-error-fn option to default-output-fn

8ea77a7

This makes it easier to provide an alternative stacktrace implementation, etc.

ptaoussanis added a commit that referenced this issue Oct 22, 2022

[new] [#317] Add :output-error-fn option to default-output-fn

847ea47

This makes it easier to provide an alternative stacktrace implementation, etc.

ptaoussanis added a commit that referenced this issue Oct 23, 2022

[new] [#317] Add :output-error-fn option to default-output-fn

39a5e5a

This makes it easier to provide an alternative stacktrace implementation, etc.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Printing a stack trace should show details for the "cause" Exceptions too #317

Printing a stack trace should show details for the "cause" Exceptions too #317

peterlindstrom123 commented Sep 11, 2020 •

edited

Loading

ptaoussanis commented Sep 12, 2020 •

edited

Loading

peterlindstrom123 commented Sep 13, 2020 •

edited

Loading

lnostdal commented Aug 18, 2021

ptaoussanis commented Mar 22, 2022

lnostdal commented Mar 23, 2022 •

edited

Loading

ptaoussanis commented Oct 18, 2022

lnostdal commented Oct 18, 2022

ptaoussanis commented Oct 19, 2022

Printing a stack trace should show details for the "cause" Exceptions too #317

Printing a stack trace should show details for the "cause" Exceptions too #317

Comments

peterlindstrom123 commented Sep 11, 2020 • edited Loading

ptaoussanis commented Sep 12, 2020 • edited Loading

peterlindstrom123 commented Sep 13, 2020 • edited Loading

lnostdal commented Aug 18, 2021

ptaoussanis commented Mar 22, 2022

lnostdal commented Mar 23, 2022 • edited Loading

ptaoussanis commented Oct 18, 2022

lnostdal commented Oct 18, 2022

ptaoussanis commented Oct 19, 2022

peterlindstrom123 commented Sep 11, 2020 •

edited

Loading

ptaoussanis commented Sep 12, 2020 •

edited

Loading

peterlindstrom123 commented Sep 13, 2020 •

edited

Loading

lnostdal commented Mar 23, 2022 •

edited

Loading