spec error output in web context

[Sven Richter]

Hi,

I just recently found out that the spec error reporting is different in different environments.

I have the following functions:

(defn search-page [{:keys [off-url off-user off-password]} search]
  (let [products (off/search-products search)
        products-with-nutriments (mapv #(off/add-nutriments % off/nutriments-to-extract) (:products products))]
    (layout/render "off/search.html" {:products products-with-nutriments :search search})))

(defn off-routes [config]
  (routes (GET "/off/search" [] (search-page config "toast"))))

where off/add-nutriments is a specced function. Now when the spec of that function fails and I call *search-page* from the REPL I get this output:

Execution error - invalid arguments to off/add-nutriments at (core.clj:9).
"" - failed: #{"kJ" "kcal" "kCal" "g" "mg"} at: [:product :nutriments :clojure.spec.alpha/pred :sugars_unit] spec: :off/unit
"" - failed: #{"kJ" "kcal" "kCal" "g" "mg"} at: [:product :nutriments :clojure.spec.alpha/pred :fat_unit] spec: :off/unit
"" - failed: #{"kJ" "kcal" "kCal" "g" "mg"} at: [:product :nutriments :clojure.spec.alpha/pred :salt_unit] spec: :off/unit
{:salt "3.5", :sugars_unit "", :energy-kcal "201.81514210652017", :energy_unit "kcal", :energy_value 202, :proteins_value "17.6", :proteins_unit "", :carbohydrates_unit "", :saturated-fat_value "8.2", :fat 12, :energy 845, :salt_value "3.5", :saturated-fat_unit "", :fat_100g 12, :sugars_value 6, :sodium_100g "1.37795275590551", :carbohydrates_value 6, :proteins_100g "17.6", :fat_unit "", :saturated-fat "8.2", :sugars_100g 6, :sodium "1.37795275590551", :sugars 6, :carbohydrates 6, :energy_100g 845, :salt_100g "3.5", :saturated-fat_100g "8.2", :salt_unit "", :carbohydrates_100g 6, :proteins "17.6", :fat_value 12} - failed: nil? at: [:product :nutriments :clojure.spec.alpha/nil] spec: :off/nutriments

which is nice and readable.

Whereas when I run the *search-page* from the started web server through the */off/search* route I get a stacktrace and a very unreadable output:

clojure.lang.ExceptionInfo: Call to #'de.sveri.getless.service.off/add-nutriments did not conform to spec. {:clojure.spec.alpha/problems ({:path [:product :nutriments :clojure.spec.alpha/nil], :pred nil?, :val {:salt "3.5", :sugars_unit "", :energy-kcal "201.81514210652017", :energy_unit "kcal", :energy_value 202, :proteins_value "17.6", :proteins_unit "", :carbohydrates_unit "", :saturated-fat_value "8.2", :fat 12, :energy 845, :salt_value "3.5", :saturated-fat_unit "", :fat_100g 12, :sugars_value 6, :sodium_100g "1.37795275590551", :carbohydrates_value 6, :proteins_100g "17.6", :fat_unit "", :saturated-fat "8.2", :sugars_100g 6, :sodium "1.37795275590551", :sugars 6, :carbohydrates 6, :energy_100g 845, :salt_100g "3.5", :saturated-fat_100g "8.2", :salt_unit "", :carbohydrates_100g 6, :proteins "17.6", :fat_value 12}, :via [:de.sveri.getless.service.off/nutriments], :in [0 :nutriments]} {:path [:product :nutriments :clojure.spec.alpha/pred :sugars_unit], :pred #{"kJ" "kcal" "kCal" "g" "mg"}, :val "", :via [:de.sveri.getless.service.off/nutriments :de.sveri.getless.service.off/unit], :in [0 :nutriments :sugars_unit]} {:path [:product :nutriments :clojure.spec.alpha/pred :fat_unit], :pred #{"kJ" "kcal" "kCal" "g" "mg"}, :val "", :via [:de.sveri.getless.service.off/nutriments :de.sveri.getless.service.off/unit], :in [0 :nutriments :fat_unit]} {:path [:product :nutriments :clojure.spec.alpha/pred :salt_unit], :pred #{"kJ" "kcal" "kCal" "g" "mg"}, :val "", :via [:de.sveri.getless.service.off/nutriments :de.sveri.getless.service.off/unit], :in [0 :nutriments :salt_unit]}), :clojure.spec.alpha/spec #object[clojure.spec.alpha$regex_spec_impl$reify__2509 0x302765e4 "clojure.spec.alpha$regex_spec_impl$reify__2509@302765e4"], :clojure.spec.alpha/value ({:image_thumb_url "https://static.openfoodfacts.org/images/products/20987664/front_de.3.100.jpg", :_keywords ["schmelzkase" "light" "toast"], :image_small_url "https://static.openfoodfacts.org/images/products/20987664/front_de.3.200.jpg", :nutriments {:salt "3.5", :sugars_unit "", :energy-kcal "201.81514210652017", :energy_unit "kcal", :energy_value 202, :proteins_value "17.6", :proteins_unit "", :carbohydrates_unit "", :saturated-fat_value "8.2", :fat 12, :energy 845, :salt_value "3.5", :saturated-fat_unit "", :fat_100g 12, :sugars_value 6, :sodium_100g "1.37795275590551", :carbohydrates_value 6, :proteins_100g "17.6", :fat_unit "", :saturated-fat "8.2", :sugars_100g 6, :sodium "1.37795275590551", :sugars 6, :carbohydrates 6, :energy_100g 845, :salt_100g "3.5", :saturated-fat_100g "8.2", :salt_unit "", :carbohydrates_100g 6, :proteins "17.6", :fat_value 12}, :ingredients_text "", :rev 10, :lang "de", :ingredients [], :id "20987664", :code "20987664", :product_name_de "Toast Light Schmelzkäse", :nutrition_data_per "100g", :quantity "250 g", :product_name "Toast Light Schmelzkäse"} #object[clojure.core$partial$fn__5841 0x73f4c45a "clojure.core$partial$fn__5841@73f4c45a"] ["energy" "fat" "saturated-fat" "carbohydrates" "sugars" "proteins" "salt" "fiber" "cholesterol" "monounsaturated-fat" "polyunsaturated-fat"]), :clojure.spec.alpha/fn de.sveri.getless.service.off/add-nutriments, :clojure.spec.alpha/args ({:image_thumb_url "https://static.openfoodfacts.org/images/products/20987664/front_de.3.100.jpg", :_keywords ["schmelzkase" "light" "toast"], :image_small_url "https://static.openfoodfacts.org/images/products/20987664/front_de.3.200.jpg", :nutriments {:salt "3.5", :sugars_unit "", :energy-kcal "201.81514210652017", :energy_unit "kcal", :energy_value 202, :proteins_value "17.6", :proteins_unit "", :carbohydrates_unit "", :saturated-fat_value "8.2", :fat 12, :energy 845, :salt_value "3.5", :saturated-fat_unit "", :fat_100g 12, :sugars_value 6, :sodium_100g "1.37795275590551", :carbohydrates_value 6, :proteins_100g "17.6", :fat_unit "", :saturated-fat "8.2", :sugars_100g 6, :sodium "1.37795275590551", :sugars 6, :carbohydrates 6, :energy_100g 845, :salt_100g "3.5", :saturated-fat_100g "8.2", :salt_unit "", :carbohydrates_100g 6, :proteins "17.6", :fat_value 12}, :ingredients_text "", :rev 10, :lang "de", :ingredients [], :id "20987664", :code "20987664", :product_name_de "Toast Light Schmelzkäse", :nutrition_data_per "100g", :quantity "250 g", :product_name "Toast Light Schmelzkäse"} #object[clojure.core$partial$fn__5841 0x73f4c45a "clojure.core$partial$fn__5841@73f4c45a"] ["energy" "fat" "saturated-fat" "carbohydrates" "sugars" "proteins" "salt" "fiber" "cholesterol" "monounsaturated-fat" "polyunsaturated-fat"]), :clojure.spec.alpha/failure :instrument, :clojure.spec.test.alpha/caller {:file "off.clj", :line 15, :var-scope de.sveri.getless.routes.off/search-page, :local-fn fn}}
	at clojure.spec.test.alpha$spec_checking_fn$conform_BANG___3024.invoke(alpha.clj:132)
	at clojure.spec.test.alpha$spec_checking_fn$fn__3026.doInvoke(alpha.clj:140)
	at clojure.lang.RestFn.invoke(RestFn.java:421)
	at de.sveri.getless.routes.off$search_page$fn__32398.invoke(off.clj:15)
	at clojure.core$mapv$fn__8445.invoke(core.clj:6912)
...

Obviously I would prefer the stacktrace and the readable output, but have no idea how to achieve that. What is the idiomatic way to print a readable spec explanation and a stacktrace in this context?

Thanks,
Sven

[Alex Miller]

How do you start the web server?

Who is printing the error?

There are functions available in clojure.main to replicate the message from the repl - you can call them yourself.

 

See https://clojure.org/reference/repl_and_main#_error_printing for more on error triage and the functions like Throwable>map, clojure.main/ex-triage, and clojure.main/ex-str. This chain of functions is what the REPL uses to produce the message below

[Sven Richter]

Am Freitag, 7. Juni 2019 15:35:41 UTC+2 schrieb Alex Miller:

How do you start the web server?

I use component to startup immutant web, I also tried with http-kit, but that didnt make a difference.

Who is printing the error?

I think thats the key point here, right now I dont know as I never bothered to figure out who prints the stacktraces.

There are functions available in clojure.main to replicate the message from the repl - you can call them yourself.

 

See https://clojure.org/reference/repl_and_main#_error_printing for more on error triage and the functions like Throwable>map, clojure.main/ex-triage, and clojure.main/ex-str. This chain of functions is what the REPL uses to produce the message below

Thanks, I will try that, but that would mean I will have to catch every potential ExceptionInfo error and check if its a spec error which is pretty cumbersome, especially as I only want to see these outputs during development (instrument is turned off in production).

Thanks,

Sven

[Alex Miller]

On Saturday, June 8, 2019 at 1:41:59 AM UTC-5, Sven Richter wrote:

Am Freitag, 7. Juni 2019 15:35:41 UTC+2 schrieb Alex Miller:

How do you start the web server?

I use component to startup immutant web, I also tried with http-kit, but that didnt make a difference.

What I mean is, what command do you use? Are using "lein ring server" or something like that?

 

Who is printing the error?

I think thats the key point here, right now I dont know as I never bothered to figure out who prints the stacktraces.

I don't think you're going to be able to improve this without understanding the answer to that question. 

 

There are functions available in clojure.main to replicate the message from the repl - you can call them yourself.

 

See https://clojure.org/reference/repl_and_main#_error_printing for more on error triage and the functions like Throwable>map, clojure.main/ex-triage, and clojure.main/ex-str. This chain of functions is what the REPL uses to produce the message below

Thanks, I will try that, but that would mean I will have to catch every potential ExceptionInfo error and check if its a spec error which is pretty cumbersome, especially as I only want to see these outputs during development (instrument is turned off in production).

The triage process knows how to print a good message for any error, not just a spec instrumentation error. There shouldn't be any conditional needed.

 

Thanks,

Sven

[Sven Richter]

Hi Alex,

I tracked it down to a minimal example with an explanation here: https://gist.github.com/sveri/1aaad9b12a8ec90d243206ab3b6073e3

The short version is. Running a specced function in the clj repl will produce meaningful output, while running in the web context with immutant will print a stacktrace with the ExceptionInfo exception.

I also tried to catch the exception and (-> ex Throwable->map clojure.main/ex-triage clojure.main/ex-str) as you suggested, which works. But like I said, I would not want to check for exceptions during production that are only thrown during development.


Do you know of a different way? Maybe a middleware would be feasible that is only added during development? What does the clj repl do to produce that output?

Thank you for your time,

Sven

[Alex Miller]

On Sun, Jun 9, 2019 at 8:43 AM 'Sven Richter' via Clojure <clo...@googlegroups.com> wrote:

Hi Alex,

I tracked it down to a minimal example with an explanation here: https://gist.github.com/sveri/1aaad9b12a8ec90d243206ab3b6073e3

The short version is. Running a specced function in the clj repl will produce meaningful output, while running in the web context with immutant will print a stacktrace with the ExceptionInfo exception.

I also tried to catch the exception and (-> ex Throwable->map clojure.main/ex-triage clojure.main/ex-str) as you suggested, which works. But like I said, I would not want to check for exceptions during production that are only thrown during development.


The generic question here is "what happens when my web request handler throws an unexpected exception?" An exception can be thrown in either dev or prod. "spec" errors are not special in this regard. Yes, you happen to be doing some extra checking in dev, but in either case you want to properly handle exceptions. The error handling chain above will give you better output for all exceptions, not just spec.

 

Do you know of a different way? Maybe a middleware would be feasible that is only added during development?

The question of how to handle exceptions in immutant is an immutant question. If you read the docstring of immutant.web/run, it tells you how to do it for ring handlers:

   For ring handlers, the actual writing of the response happens after
   your hander returns. If an exception occurs on the write (the most
   common case being an IOException because the client has gone away),
   the default behavior is to log the exception. If you would like to
   be able to handle that exception yourself, you can return a function
   in the ring response under :write-error-handler. This function will
   be called with the exception, the request map, and the response map
   if an exception occurs when writing the response. Note that this
   handler can't actually affect the response. If you would prefer
   a global handler, see immutant.web.middleware/wrap-write-error-handling.

It might be a reasonable improvement to immutant to do this better error printing by default (with the caveat that you have to be on Clojure 1.10 to do so). 

 

What does the clj repl do to produce that output?

It catches exceptions during the read, eval, and print phases and calls

(-> ex Throwable->map clojure.main/ex-triage clojure.main/ex-str)

Thank you for your time,

Sven

Am Samstag, 8. Juni 2019 20:52:27 UTC+2 schrieb Alex Miller:

On Saturday, June 8, 2019 at 1:41:59 AM UTC-5, Sven Richter wrote:

Am Freitag, 7. Juni 2019 15:35:41 UTC+2 schrieb Alex Miller:

How do you start the web server?

I use component to startup immutant web, I also tried with http-kit, but that didnt make a difference.

What I mean is, what command do you use? Are using "lein ring server" or something like that?

 

Who is printing the error?

I think thats the key point here, right now I dont know as I never bothered to figure out who prints the stacktraces.

I don't think you're going to be able to improve this without understanding the answer to that question. 

 

There are functions available in clojure.main to replicate the message from the repl - you can call them yourself.

 

See https://clojure.org/reference/repl_and_main#_error_printing for more on error triage and the functions like Throwable>map, clojure.main/ex-triage, and clojure.main/ex-str. This chain of functions is what the REPL uses to produce the message below

Thanks, I will try that, but that would mean I will have to catch every potential ExceptionInfo error and check if its a spec error which is pretty cumbersome, especially as I only want to see these outputs during development (instrument is turned off in production).

The triage process knows how to print a good message for any error, not just a spec instrumentation error. There shouldn't be any conditional needed.

 

Thanks,

Sven

--
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+u...@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 a topic in the Google Groups "Clojure" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/clojure/RKb6XOjCK8A/unsubscribe.
To unsubscribe from this group and all its topics, send an email to clojure+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/clojure/d667e44b-397f-4a34-9c95-a0ab9adc4f54%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Sven Richter]

Am Sonntag, 9. Juni 2019 16:15:38 UTC+2 schrieb Alex Miller:

On Sun, Jun 9, 2019 at 8:43 AM 'Sven Richter' via Clojure <clo...@googlegroups.com> wrote:

I also tried to catch the exception and (-> ex Throwable->map clojure.main/ex-triage clojure.main/ex-str) as you suggested, which works. But like I said, I would not want to check for exceptions during production that are only thrown during development.


The generic question here is "what happens when my web request handler throws an unexpected exception?" An exception can be thrown in either dev or prod. "spec" errors are not special in this regard. Yes, you happen to be doing some extra checking in dev, but in either case you want to properly handle exceptions. The error handling chain above will give you better output for all exceptions, not just spec.

 

 I would like to respectfully disagree here. The docs explicitly state that it is not advised to use instrument in production. So in production I will never see the same error messages regarding spec as in development, at least regarding to fdef. So what is a useful exception during development with a useful output in production it might become visible just a few functions down the stack becoming a NullpointerException, for instance. This is especially true in cases like my one, when I consume a third-party web service where the interface is prone to change.

Do you know of a different way? Maybe a middleware would be feasible that is only added during development?

The question of how to handle exceptions in immutant is an immutant question. If you read the docstring of immutant.web/run, it tells you how to do it for ring handlers:

   For ring handlers, the actual writing of the response happens after
   your hander returns. If an exception occurs on the write (the most
   common case being an IOException because the client has gone away),
   the default behavior is to log the exception. If you would like to
   be able to handle that exception yourself, you can return a function
   in the ring response under :write-error-handler. This function will
   be called with the exception, the request map, and the response map
   if an exception occurs when writing the response. Note that this
   handler can't actually affect the response. If you would prefer
   a global handler, see immutant.web.middleware/wrap-write-error-handling.

I should have looked up the immutant docs myself. Unfortunately I was totally unaware of the different possible outcomes of spec errors.

Anyway, thank you very much again for your explanations, I think I got it all together now and learned something new today :-)