Can slingshot/try+ and then catch Object really catch any error?
366 views
Skip to first unread message
lawrence...@gmail.com
Oct 8, 2017, 11:13:10 PM10/8/17
to Clojure
I'm trying to use a Zach Tellman's durable-queue to pass information from one part of my app to another. I have 3 queues. I also have a function that runs every 30 seconds, that is suppose to report some statistics for me:
(fn []
(future
(slingshot/try+
(errors/log "Resource usage: "
(monitoring/show-stats-regarding-resources-used-by-this-app))
(errors/log "Stats about from-mysql-to-tables-queue: " (durable/stats from-mysql-to-tables-queue))
(errors/log "Stats about from-tables-to-topics-queue: " (durable/stats from-tables-to-topics-queue))
(errors/log "Stats about the from-topics-to-persistence-queue: " (durable/stats from-topics-to-persistence-queue))
(catch Object o
(slingshot/throw+ {
:type ::cycle-resource-usage-report
:error o
}
)))))
I think there is an error here, because I see the first (errors/log) but typically not anything after that. Can I rely on the fact that this should catch anything:
(catch Object o
Because it doesn't seem to work. Instead, the app runs for 8 minutes, then prints data about the queues just once, then never again. Assuming an error is occuring, why can't I see the error?
{:timestamp "17-10-09 01:27:45", :level :trace, :hostname "ip-172-31-4-54", :message ("STARTING!!!!")}
Loading class `com.mysql.jdbc.Driver'. This is deprecated. The new driver class is `com.mysql.cj.jdbc.Driver'. The driver is automatically registered via the SPI and manual loading of the driver class is generally unnecessary.
{:timestamp "17-10-09 01:28:16", :level :trace, :hostname "ip-172-31-4-54", :message ("\n\n\n\n\nResource usage: " "Memory in use (percentage/used/max-heap): (\"67%\" \"2414M\" \"3568M\")\n\nCPU usage (how-many-cpu's/load-average): [4 1.56]\n\nFree memory in jvm: [1201758848]")}
{:timestamp "17-10-09 01:28:49", :level :trace, :hostname "ip-172-31-4-54", :message ("\n\n\n\n\nResource usage: " "Memory in use (percentage/used/max-heap): (\"81%\" \"2900M\" \"3568M\")\n\nCPU usage (how-many-cpu's/load-average): [4 2.64]\n\nFree memory in jvm: [699798216]")}
;; removing redundant entries
{:timestamp "17-10-09 01:34:48", :level :trace, :hostname "UnknownHost", :message ("\n\n\n\n\nResource usage: " "Memory in use (percentage/used/max-heap): (\"87%\" \"3118M\" \"3568M\")\n\nCPU usage (how-many-cpu's/load-average): [4 3.77]\n\nFree memory in jvm: [471249616]")}
{:timestamp "17-10-09 01:35:17", :level :trace, :hostname "ip-172-31-4-54", :message ("\n\n\n\n\nResource usage: " "Memory in use (percentage/used/max-heap): (\"87%\" \"3120M\" \"3568M\")\n\nCPU usage (how-many-cpu's/load-average): [4 3.79]\n\nFree memory in jvm: [468602192]")}
{:timestamp "17-10-09 01:35:35", :level :trace, :hostname "ip-172-31-4-54", :message ("\nStats about from-mysql-to-tables-queue: " {"message" {:num-slabs 1, :num-active-slabs 1, :enqueued 306671, :retried 0, :completed 306660, :in-progress 8}})}
{:timestamp "17-10-09 01:35:50", :level :trace, :hostname "ip-172-31-4-54", :message ("\nStats about from-tables-to-topics-queue: " {})}
{:timestamp "17-10-09 01:35:50", :level :trace, :hostname "ip-172-31-4-54", :message ("\nStats about the from-topics-to-persistence-queue: " {})}
{:timestamp "17-10-09 01:36:15", :level :trace, :hostname "ip-172-31-4-54", :message ("\n\n\n\n\nResource usage: " "Memory in use (percentage/used/max-heap): (\"28%\" \"1007M\" \"3568M\")\n\nCPU usage (how-many-cpu's/load-average): [4 4.14]\n\nFree memory in jvm: [1868654000]")}
So 8 minutes after the app starts, it print the lines with stats about the queues, just this one time, and then never again. I think an error must occur inside of the function that is suppose to report the queues. What would I have to do to see that error?
My core/main function looks like this:
(defn -main [& args]
(slingshot/try+
;; 2017-10-04 -- see this:
(System/setProperty "https.protocols" "TLSv1.1")
(.addShutdownHook (Runtime/getRuntime)
(Thread.
#(do (println "addShutdownHook triggered. This app is shutting down.")
(stop))))
;; 2017-07-12 -- stealing code from here:
;; Assuming require [clojure.tools.logging :as log]
(Thread/setDefaultUncaughtExceptionHandler
(reify Thread$UncaughtExceptionHandler
(uncaughtException [_ thread ex]
(println ex "Uncaught background exception on thread " (.getName thread) " Caught by Thread/setDefaultUncaughtExceptionHandler in core/main.")
(throw (ex-info "/setDefaultUncaughtExceptionHandler. The app has died!")))))
(start)
(catch Exception e
(println e)
(stack/parse-exception e)
(throw (ex-info "The app has died!")))
(catch Object o
(println o)
(throw (ex-info "The app has died!")))))
What else could I do to either kill the app at the moment of error or catch it at the top and print the error?
lawrence...@gmail.com
Oct 8, 2017, 11:18:31 PM10/8/17
to Clojure
(errors/log) simply writes to the Timbre logging library. I thought perhaps there was an error in my Timbre configuration, so I wrapped those functions in try/catch, but I still don't see anything. I'm trying this as my Timbre config:
(defn- set-timbre-level []
(timbre/set-config!
{:level :trace ; e/o #{:trace :debug :info :warn :error :fatal :report}
:output-fn (fn [data]
(slingshot/try+
(clojure.string/join "\n" data)
(catch Object o
(slingshot/throw+ {
:type ::output-fn-of-timbre
:error o
}
))))
:appenders {
;; Appender id
:for-stdout {
:enabled? true
:async? false
:min-level nil
:rate-limit [[1 250] [10 5000]] ; 1/250ms, 10/5s
:output-fn :inherit
;; Appender's fn
:fn (fn
[{:keys [vargs_ hostname_ timestamp_ level output-fn] :as args}]
(slingshot/try+
(let [
messages (map (fn [msg] { :timestamp @timestamp_
:level level
:hostname @hostname_
:message msg })
@vargs_)
]
(println (str (temporal/current-time-as-string) "\n" (output-fn messages))))
(catch Object o
(slingshot/throw+ {
:type ::for-stdout-fn-of-timbre
:error o
}
))))}}}))
lawrence...@gmail.com
Oct 8, 2017, 11:22:36 PM10/8/17
to Clojure
More generally, I'm having trouble seeing any kind of logging messages. Even when I delete this Timbre config, and simply go with Timbre defaults, and set the level to "trace", I only erratically see anything printed to the logs. I assume there are messages dying in background threads, but I have a bit of code, which I stole from a blog post by Stuart Sierra, and which I put in my core/main function, which should, I assumed, reveal to me errors thrown from background threads.
lawrence...@gmail.com
Oct 8, 2017, 11:27:49 PM10/8/17
to Clojure
Using spit to an append to a log file, I end up seeing much more than what I can see from Timbre. The app writes a few lines, then dies:
("\n\n\n\n\nResource usage: " "Memory in use (percentage/used/max-heap): (\"3%\" \"133M\" \"3568M\")\n\nCPU usage (how-many-cpu's/load-average): [4 0.0]\n\nFree memory in jvm: [252719920]")
("\nStats about from-mysql-to-tables-queue: " {"message" {:num-slabs 1, :num-active-slabs 1, :enqueued 389, :retried 10, :completed 378, :in-progress 1}})
("\nStats about from-tables-to-topics-queue: " {})
("\nStats about the from-topics-to-persistence-queue: " {})
("\n\n\n\n\nResource usage: " "Memory in use (percentage/used/max-heap): (\"3%\" \"134M\" \"3568M\")\n\nCPU usage (how-many-cpu's/load-average): [4 0.0]\n\nFree memory in jvm: [251769008]")
("\nStats about from-mysql-to-tables-queue: " {"message" {:num-slabs 1, :num-active-slabs 1, :enqueued 389, :retried 10, :completed 378, :in-progress 1}})
("\nStats about from-tables-to-topics-queue: " {})
("\nStats about the from-topics-to-persistence-queue: " {})
Still, I feel like I've got everything wrapped in slingshot/try+ and catch and throw, yet I don't see the error that is killing the app. Is that because of (catch Object) doesn't catch all the errors that I should be checking for, or is that because my logging functions just don't write them?
lawrence...@gmail.com
Oct 8, 2017, 11:43:06 PM10/8/17
to Clojure
So, for instance, this says that 10 documents were retried:
{"message" {:num-slabs 1, :num-active-slabs 1, :enqueued 389, :retried 10, :completed 378, :in-progress 1}}
The only place that I call retry! is in this catch block (this function runs in a background thread):
(defn advance
[message]
{:pre [
(= (type message) durable_queue.Task)
]}
(slingshot/try+
(doseq [[k v] @message]
(when-not (or
(= :how-many-rows-and-fields-from-database k)
(= :database-table k)
(= :denormalized-id k)
(= :topic k))
(transform
(get @message :denormalized-id :missing-denormalized-id)
k
v
(get @message :topic :missing-topic)
(get @message :how-many-rows-and-fields-from-database :missing-how-many-rows-and-fields-from-database))))
(durable/complete! message)
(catch Object o
(durable/retry! message)
(slingshot/throw+ {
:type ::advance
:error o
}
))))
So clearly, the code has a problem with some of the documents, and so an error is thrown, and it is caught by the catch block. I would love to see the error. I can not. If I put println in the catch block, the message never shows up in the terminal. Likewise if I use Timbre.
I would love to see the error object. My inability to see the error objects has crippled my productivity.
Can anyone tell me what I need to do to see these errors?
Timothy Baldridge
Oct 8, 2017, 11:46:26 PM10/8/17
to clo...@googlegroups.com
I don't think you can catch an Object on the JVM can you? What happens if you catch Throwable?
--
You received this message because you are subscribed to the Google
Groups "Clojure" group.
To post to this group, send email to clo...@googlegroups.com
Note that posts from new members are moderated - please be patient with your first post.
To unsubscribe from this group, send email to
clojure+unsubscribe@googlegroups.com
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en
---
You received this message because you are subscribed to the Google Groups "Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clojure+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
“One of the main causes of the fall of the Roman Empire was that–lacking zero–they had no way to indicate successful termination of their C programs.”
(Robert Firth)
(Robert Firth)
lawrence...@gmail.com
Oct 9, 2017, 12:14:02 AM10/9/17
to Clojure
Well, the people behind Slingshot have suggested it as the Slingshot version of catch Exception, but I like your idea and I'll try it.
Having said that, as I said in my last post, the only place I call (retry!) is inside the catch block, so the code does end up inside of that catch block. But I never see any results of printing or throwing from inside the catch block.
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en
---
You received this message because you are subscribed to the Google Groups "Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clojure+u...@googlegroups.com.
lawrence...@gmail.com
Oct 9, 2017, 12:18:26 AM10/9/17
to Clojure
It's a bit absurd, but at the end of core/main I'm now catching Exceptions, Throwable and Object. But this doesn't seem to help me see what is happening on background threads.
(defn -main [& args]
(slingshot/try+
;; 2017-10-04 -- see this:
(System/setProperty "https.protocols" "TLSv1.1")
(.addShutdownHook (Runtime/getRuntime)
(Thread.
#(do (println "addShutdownHook triggered. This app is shutting down.")
(stop))))
;; 2017-07-12 -- stealing code from here:
;; Assuming require [clojure.tools.logging :as log]
(Thread/setDefaultUncaughtExceptionHandler
(reify Thread$UncaughtExceptionHandler
(uncaughtException [_ thread ex]
(println ex "Uncaught background exception on thread " (.getName thread) " Caught by Thread/setDefaultUncaughtExceptionHandler in core/main.")
(throw (ex-info "/setDefaultUncaughtExceptionHandler. The app has died!")))))
(start)
(catch Exception e
(println e)
(stack/parse-exception e)
(throw (ex-info "The app has died!")))
(catch Throwable t
(println t)
(throw (ex-info "The app has died!")))
(catch Object o
(println o)
(throw (ex-info "The app has died!")))))
On Sunday, October 8, 2017 at 11:46:26 PM UTC-4, tbc++ wrote:
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en
---
You received this message because you are subscribed to the Google Groups "Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clojure+u...@googlegroups.com.
lawrence...@gmail.com
Oct 9, 2017, 12:20:40 AM10/9/17
to Clojure
Possibly this is a complication arising from the use of Slingshot? It would take a 2 maybe hours to completely tear Slingshot out of this app, but I would do that if I thought I would then be able to see the error messages.
On Sunday, October 8, 2017 at 11:46:26 PM UTC-4, tbc++ wrote:
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en
---
You received this message because you are subscribed to the Google Groups "Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clojure+u...@googlegroups.com.
lawrence...@gmail.com
Oct 9, 2017, 12:29:24 AM10/9/17
to Clojure
I just re-wrote much of the code to run on the main thread. And so now I can see the error message (which was about a nil value in a place where I was certain there would be no nil values). Which is great. But since the app does a lot of I/O, I would like to for this app to be multi-threaded. But I need to figure out a way that I can see errors that happen in background threads.
On Sunday, October 8, 2017 at 11:46:26 PM UTC-4, tbc++ wrote:
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en
---
You received this message because you are subscribed to the Google Groups "Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clojure+u...@googlegroups.com.
Timothy Baldridge
Oct 9, 2017, 12:31:16 AM10/9/17
to clo...@googlegroups.com
What REPL are you using? A rather nasty side-effect of NRepl is that it tends to send messages from non-main-threads to weird places.
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en
---
You received this message because you are subscribed to the Google Groups "Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clojure+unsubscribe@googlegroups.com.
lawrence...@gmail.com
Oct 9, 2017, 2:40:01 AM10/9/17
to Clojure
I'm using Cider in Emacs, but the problems I face only occur when I've created an uberjar and I try to run the app on the server. In the REPL I only work with small amounts of data, whereas on the server I work with a few million. Not sure how to get around that as I'm working from my apartment and my client has AWS roles set up so that the database can only be reached from the server.
I'm fine with writing everything to a log file, if that would catch messages from background threads, though I'm curious what setups others use? I'm a bit surprised I can't get Timbre to work the way I want to, though I have not put much effort into configuring it to write to a log file. In the past I've been happy to have it write to stdout and then (in production) Supervisord would take the stdout and write it to a log file.
I'm curious what others do for logging?
Shantanu Kumar
Oct 9, 2017, 2:56:24 AM10/9/17
to Clojure
I'm curious what others do for logging?
At Concur we using Cambium https://github.com/kumarshantanu/cambium that's being moved (WIP) here: https://github.com/cambium-clojure
Cambium wraps SLF4j and gives a Clojure API (which extends tools.logging) to use it's MDC feature.
Shantanu
lawrence...@gmail.com
Oct 9, 2017, 3:01:57 AM10/9/17
to Clojure
Kumar,
Just so you know, on this page:
lawrence...@gmail.com
Oct 9, 2017, 3:04:41 AM10/9/17
to Clojure
Shantanu Kumar, thanks for that, I might try it. I assume you've never had the problem I'm talking about, of messages on background threads that disappear?
On Monday, October 9, 2017 at 2:56:24 AM UTC-4, Shantanu Kumar wrote:
Shantanu Kumar
Oct 9, 2017, 3:06:08 AM10/9/17
to Clojure
On Monday, 9 October 2017 12:31:57 UTC+5:30, lawrence...@gmail.com wrote:
Kumar,Just so you know, on this page:
I'm sorry the https://cambium-clojure.github.io/ site is still WIP, hence not announced publicly yet. (I hope to be able to do that in some time.)
Shantanu
Shantanu Kumar
Oct 9, 2017, 3:16:54 AM10/9/17
to Clojure
On Monday, 9 October 2017 12:34:41 UTC+5:30, lawrence...@gmail.com wrote:
Shantanu Kumar, thanks for that, I might try it. I assume you've never had the problem I'm talking about, of messages on background threads that disappear?
Logback (the SLF4j impl we use) is capable of logging from multiple threads. I always set the default uncaught handler to log any exception arising from background threads:
Stuart Sierra also wrote about how to do this: https://stuartsierra.com/2015/05/27/clojure-uncaught-exceptions
If you do this step correctly, you might be able to notice the background-thread exceptions even with a plain `println` call.
Shantanu
Gary Verhaegen
Oct 9, 2017, 5:20:05 AM10/9/17
to clo...@googlegroups.com
Not easy to be positive without more information about your code base, but the only times I had symptoms that resemble what you describe, the problem was that the JVM died before printing. That is, you have multiple threads, and printing is asynchronous at many levels (even the terminal itself buffers stuff). If the app dies in that condition it's actually fairly common that messages aren't visible, even though the statement and sometimes a few next ones have indeed run. Nothing to do with Timbre as far as I can tell.
Maybe try to give your app a bit more wall-clock time between the error and killing the process? (Note: I don't think you can do that by sleeping in the shutdownhook as the JVM will not necessarily wait on that one.)
--
You received this message because you are subscribed to the Google
Groups "Clojure" group.
To post to this group, send email to clo...@googlegroups.com
Note that posts from new members are moderated - please be patient with your first post.
To unsubscribe from this group, send email to
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en
---
You received this message because you are subscribed to the Google Groups "Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email to clojure+unsubscribe@googlegroups.com.
Matching Socks
Oct 9, 2017, 8:12:33 AM10/9/17
to Clojure
The linked page https://stuartsierra.com/2015/05/27/clojure-uncaught-exceptions also says "Another wrinkle: exceptions inside a future are always caught by the Future. The exception will not be thrown until something calls Future.get (deref in Clojure)." So you would need to review the pattern of "(try (future (catch (throw".
lawrence...@gmail.com
Oct 9, 2017, 2:23:05 PM10/9/17
to Clojure
MatchingSocks, thanks for that. I think the pattern I followed everywhere was:
(future
(slingshot/try+
;;; some code
(catch Object o
(println o))))
So I think I do catch everything inside of each future that I launch. But I will check again. Perhaps I missed one somewhere.
lawrence...@gmail.com
Oct 9, 2017, 2:24:30 PM10/9/17
to Clojure
Gary Verhaegen, thanks for that. The idea of buffers and threads dying is a good one and gives me something to look for.
Sean Corfield
Oct 9, 2017, 2:59:35 PM10/9/17
to clo...@googlegroups.com
Timbre has a logged-future macro that you can use instead of future so that exceptions are automatically logged.
Sean Corfield -- (970) FOR-SEAN -- (904) 302-SEAN
An Architect's View -- http://corfield.org/
"If you're not annoying somebody, you're not really alive."
-- Margaret Atwood
From: clo...@googlegroups.com <clo...@googlegroups.com> on behalf of lawrence...@gmail.com <lawrence...@gmail.com>
Sent: Monday, October 9, 2017 11:23:05 AM
To: Clojure
Subject: Re: Can slingshot/try+ and then catch Object really catch any error?
Sent: Monday, October 9, 2017 11:23:05 AM
To: Clojure
Subject: Re: Can slingshot/try+ and then catch Object really catch any error?
--
You received this message because you are subscribed to the Google
Groups "Clojure" group.
To post to this group, send email to clo...@googlegroups.com
Note that posts from new members are moderated - please be patient with your first post.
To unsubscribe from this group, send email to
Groups "Clojure" group.
To post to this group, send email to clo...@googlegroups.com
Note that posts from new members are moderated - please be patient with your first post.
To unsubscribe from this group, send email to
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en
---
You received this message because you are subscribed to the Google Groups "Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email to
clojure+u...@googlegroups.com.
lawrence...@gmail.com
Oct 9, 2017, 4:55:26 PM10/9/17
to Clojure
Sean Corfield, thank you, that is a great tip.
lawrence...@gmail.com
Oct 9, 2017, 5:01:06 PM10/9/17
to Clojure
I figured a common reason for error messages to disappear is when there is another Exception inside of the catch block, so the catch block itself dies without doing anything.
I had copy-and-pasted this from somewhere, without looking at it much:
(catch Exception e
(println e)
(stack/parse-exception e)
(throw (ex-info "The app has died!")))
It took me awhile before I saw this:
:type clojure.lang.ArityException
:message Wrong number of args (1) passed to: core/ex-info
:at [clojure.lang.AFn throwArity AFn.java 429]}]
Looking here reveals that there is no one argument version of ex-info:
My fault, obviously, for being careless when mixing different kinds of error reporting.
On Monday, October 9, 2017 at 2:59:35 PM UTC-4, Sean Corfield wrote:
Reply all
Reply to author
Forward
0 new messages