bhb / expound

Human-optimized error messages for clojure.spec
Eclipse Public License 1.0
924 stars 24 forks source link

ClassCastException from `expound-str` when running in AWS Lambda #216

Closed aviflax closed 3 years ago

aviflax commented 3 years ago

I’m using Expound in an AWS Lambda function to provide useful error messages when the invocation payload is invalid. This works when I test it locally using a vanilla JRE, but fails when running in AWS Lambda.

I don’t understand the error message, so I don’t think I can be any more helpful than just providing it as a bug report and asking: is there something we can do about this?

The error:


14:14:28 ERROR - apx-rest-executor.handler - Event handling failed: #error {
--
:cause class clojure.pprint.proxy$java.io.Writer$IDeref$PrettyFlush$4923d848 cannot be cast to class clojure.pprint.PrettyFlush (clojure.pprint.proxy$java.io.Writer$IDeref$PrettyFlush$4923d848 is in unnamed module of loader lambdainternal.CustomerClassLoader @3feba861; clojure.pprint.PrettyFlush is in unnamed module of loader clojure.lang.DynamicClassLoader @3bc18fec)
:via
[{:type java.lang.ClassCastException
:message class clojure.pprint.proxy$java.io.Writer$IDeref$PrettyFlush$4923d848 cannot be cast to class clojure.pprint.PrettyFlush (clojure.pprint.proxy$java.io.Writer$IDeref$PrettyFlush$4923d848 is in unnamed module of loader lambdainternal.CustomerClassLoader @3feba861; clojure.pprint.PrettyFlush is in unnamed module of loader clojure.lang.DynamicClassLoader @3bc18fec)
:at [clojure.pprint$write$fn__7900 invoke pprint_base.clj 234]}]
:trace
[[clojure.pprint$write$fn__7900 invoke pprint_base.clj 234]
[clojure.pprint$write invokeStatic pprint_base.clj 233]
[clojure.pprint$write doInvoke pprint_base.clj 197]
[clojure.lang.RestFn invoke RestFn.java 439]
[expound.printer$pprint_str invokeStatic printer.cljc 247]
[expound.printer$pprint_str invoke printer.cljc 242]
[expound.printer$expand_spec invokeStatic printer.cljc 255]
[expound.printer$expand_spec invoke printer.cljc 249]
[expound.printer$simple_spec_or_name invokeStatic printer.cljc 258]
[expound.printer$simple_spec_or_name invoke printer.cljc 257]
[expound.printer$print_spec_keys_STAR_$fn__33637 invoke printer.cljc 276]
[clojure.core$map$fn__19590 invoke core.clj 2759]
[clojure.lang.LazySeq sval LazySeq.java 42]
[clojure.lang.LazySeq seq LazySeq.java 51]
[clojure.lang.RT seq RT.java 535]
[clojure.core$seq__19017 invokeStatic core.clj 139]
[clojure.core$seq__19017 invoke core.clj 139]
[clojure.core$sort invokeStatic core.clj 3101]
[clojure.core$sort invoke core.clj 3090]
[clojure.core$sort_by invokeStatic core.clj 3119]
[clojure.core$sort_by invoke core.clj 3107]
[clojure.core$sort_by invokeStatic core.clj 3117]
[clojure.core$sort_by invoke core.clj 3107]
[expound.printer$print_spec_keys_STAR_ invokeStatic printer.cljc 277]
[expound.printer$print_spec_keys_STAR_ invoke printer.cljc 266]
[expound.printer$print_spec_keys$fn__33644 invoke printer.cljc 281]
[expound.printer$print_spec_keys invokeStatic printer.cljc 280]
[expound.printer$print_spec_keys invoke printer.cljc 279]
[expound.alpha$explain_missing_keys invokeStatic alpha.cljc 324]
[expound.alpha$explain_missing_keys invoke alpha.cljc 315]
[expound.alpha$eval33854$fn__33855 invoke alpha.cljc 390]
[clojure.lang.MultiFn invoke MultiFn.java 261]
[expound.alpha$eval33858$fn__33859 invoke alpha.cljc 401]
[clojure.lang.MultiFn invoke MultiFn.java 261]
[expound.alpha$print_explain_data$iter__34098__34102$fn__34103$fn__34104 invoke alpha.cljc 867]
[expound.alpha$print_explain_data$iter__34098__34102$fn__34103 invoke alpha.cljc 865]
[clojure.lang.LazySeq sval LazySeq.java 42]
[clojure.lang.LazySeq seq LazySeq.java 51]
[clojure.lang.RT seq RT.java 535]
[clojure.core$seq__19017 invokeStatic core.clj 139]
[clojure.core$seq__19017 invoke core.clj 139]
[clojure.core$apply invokeStatic core.clj 667]
[clojure.core$apply invoke core.clj 662]
[expound.alpha$print_explain_data invokeStatic alpha.cljc 864]
[expound.alpha$print_explain_data invoke alpha.cljc 850]
[expound.alpha$printer_str invokeStatic alpha.cljc 1005]
[expound.alpha$printer_str invoke alpha.cljc 987]
[expound.alpha$expound_str invokeStatic alpha.cljc 1065]
[expound.alpha$expound_str invoke alpha.cljc 1060]
[apx_rest_executor.specs$valid_QMARK__BANG_ invokeStatic specs.clj 35]
[apx_rest_executor.specs$valid_QMARK__BANG_ invoke specs.clj 32]
[apx_rest_executor.event.trade_approved$eval34379$fn__34381 invoke trade_approved.clj 76]
[clojure.lang.MultiFn invoke MultiFn.java 234]
[apx_rest_executor.handler$_handleRequest invokeStatic handler.clj 78]
[apx_rest_executor.handler$_handleRequest invoke handler.clj 68]
[apx_rest_executor.handler handleRequest nil -1]
[lambdainternal.EventHandlerLoader$2 call EventHandlerLoader.java 899]
[lambdainternal.AWSLambda startRuntime AWSLambda.java 258]
[lambdainternal.AWSLambda startRuntime AWSLambda.java 192]
[lambdainternal.AWSLambda main AWSLambda.java 187]]}
java.lang.ClassCastException: class clojure.pprint.proxy$java.io.Writer$IDeref$PrettyFlush$4923d848 cannot be cast to class clojure.pprint.PrettyFlush (clojure.pprint.proxy$java.io.Writer$IDeref$PrettyFlush$4923d848 is in unnamed module of loader lambdainternal.CustomerClassLoader @3feba861; clojure.pprint.PrettyFlush is in unnamed module of loader clojure.lang.DynamicClassLoader @3bc18fec)
at clojure.pprint$write$fn__7900.invoke(pprint_base.clj:234)
at clojure.pprint$write.invokeStatic(pprint_base.clj:233)
at clojure.pprint$write.doInvoke(pprint_base.clj:197)
at clojure.lang.RestFn.invoke(RestFn.java:439)
at expound.printer$pprint_str.invokeStatic(printer.cljc:247)
at expound.printer$pprint_str.invoke(printer.cljc:242)
at expound.printer$expand_spec.invokeStatic(printer.cljc:255)
at expound.printer$expand_spec.invoke(printer.cljc:249)
at expound.printer$simple_spec_or_name.invokeStatic(printer.cljc:258)
at expound.printer$simple_spec_or_name.invoke(printer.cljc:257)
at expound.printer$print_spec_keys_STAR_$fn__33637.invoke(printer.cljc:276)
at clojure.core$map$fn__19590.invoke(core.clj:2759)
at clojure.lang.LazySeq.sval(LazySeq.java:42)
at clojure.lang.LazySeq.seq(LazySeq.java:51)
at clojure.lang.RT.seq(RT.java:535)
at clojure.core$seq__19017.invokeStatic(core.clj:139)
at clojure.core$seq__19017.invoke(core.clj:139)
at clojure.core$sort.invokeStatic(core.clj:3101)
at clojure.core$sort.invoke(core.clj:3090)
at clojure.core$sort_by.invokeStatic(core.clj:3119)
at clojure.core$sort_by.invoke(core.clj:3107)
at clojure.core$sort_by.invokeStatic(core.clj:3117)
at clojure.core$sort_by.invoke(core.clj:3107)
at expound.printer$print_spec_keys_STAR_.invokeStatic(printer.cljc:277)
at expound.printer$print_spec_keys_STAR_.invoke(printer.cljc:266)
at expound.printer$print_spec_keys$fn__33644.invoke(printer.cljc:281)
at expound.printer$print_spec_keys.invokeStatic(printer.cljc:280)
at expound.printer$print_spec_keys.invoke(printer.cljc:279)
at expound.alpha$explain_missing_keys.invokeStatic(alpha.cljc:324)
at expound.alpha$explain_missing_keys.invoke(alpha.cljc:315)
at expound.alpha$eval33854$fn__33855.invoke(alpha.cljc:390)
at clojure.lang.MultiFn.invoke(MultiFn.java:261)
at expound.alpha$eval33858$fn__33859.invoke(alpha.cljc:401)
at clojure.lang.MultiFn.invoke(MultiFn.java:261)
at expound.alpha$print_explain_data$iter__34098__34102$fn__34103$fn__34104.invoke(alpha.cljc:867)
at expound.alpha$print_explain_data$iter__34098__34102$fn__34103.invoke(alpha.cljc:865)
at clojure.lang.LazySeq.sval(LazySeq.java:42)
at clojure.lang.LazySeq.seq(LazySeq.java:51)
at clojure.lang.RT.seq(RT.java:535)
at clojure.core$seq__19017.invokeStatic(core.clj:139)
at clojure.core$seq__19017.invoke(core.clj:139)
at clojure.core$apply.invokeStatic(core.clj:667)
at clojure.core$apply.invoke(core.clj:662)
at expound.alpha$print_explain_data.invokeStatic(alpha.cljc:864)
at expound.alpha$print_explain_data.invoke(alpha.cljc:850)
at expound.alpha$printer_str.invokeStatic(alpha.cljc:1005)
at expound.alpha$printer_str.invoke(alpha.cljc:987)
at expound.alpha$expound_str.invokeStatic(alpha.cljc:1065)
at expound.alpha$expound_str.invoke(alpha.cljc:1060)
at apx_rest_executor.specs$valid_QMARK__BANG_.invokeStatic(specs.clj:35)
at apx_rest_executor.specs$valid_QMARK__BANG_.invoke(specs.clj:32)
at apx_rest_executor.event.trade_approved$eval34379$fn__34381.invoke(trade_approved.clj:76)
at clojure.lang.MultiFn.invoke(MultiFn.java:234)
at apx_rest_executor.handler$_handleRequest.invokeStatic(handler.clj:78)
at apx_rest_executor.handler$_handleRequest.invoke(handler.clj:68)
at apx_rest_executor.handler.handleRequest(Unknown Source)
at lambdainternal.EventHandlerLoader$2.call(EventHandlerLoader.java:899)
at lambdainternal.AWSLambda.startRuntime(AWSLambda.java:258)
at lambdainternal.AWSLambda.startRuntime(AWSLambda.java:192)
at lambdainternal.AWSLambda.main(AWSLambda.java:187)
aviflax commented 3 years ago

Ah, the runtime is Java 11 (Corretto)

bhb commented 3 years ago

Thanks for reporting this!

I'm not super familiar with Lambda. Are you using a tool to create an uberjar? If so, which tool? Can you reproduce by running the uberjar locally?

The reason I ask is that the error message matches these bugs in various tools:

https://github.com/healthfinch/depstar/issues/10 https://github.com/cursive-ide/gradle-clojure/issues/7 https://github.com/cursive-ide/gradle-clojure/issues/8 https://github.com/ptaoussanis/timbre/issues/254

If you can reproduce locally, I wonder if it's possible to shrink the repro by just using clojure.pprint directly in your code and invoking it.

aviflax commented 3 years ago

Ah, yes, I’m using depstar. I’ll try to reproduce locally. Thanks!

bhb commented 3 years ago

Did you have any luck tracking down a repro for this locally?

aviflax commented 3 years ago

@bhb I just spent an hour trying to reproduce, but so far I have been unsuccessful. If you have any suggestions, please share. Thanks!

aviflax commented 3 years ago

🤔 I guess the next thing would be to try to run the repro code in an actual Lambda “function” on the actual Lambda service. I don’t have time for that right now… maybe later this week…

vemv commented 3 years ago

In case it helps, I see lambdainternal.CustomerClassLoader as part of the stacktrace. Perhaps it's worth understanding how that classloader and Clojure's own interact.

vemv commented 3 years ago

As this piqued my curiosity I asked around in #aws-lambda:

image

You might have luck disabling AOT and/or choosing a specific lambda runtime. Of course that might affect cold starts etc - would depend on the use case.

bhb commented 3 years ago

@aviflax I'm going to close this, since it appears to be an issue with the classloader.