immutant

http://immutant.org Note: dev discussion happens in #immutant on FreeNode IRC.
timgilbert 2016-12-15T16:39:29.000078Z

Hi all, I'm seeing some peculiar Undertow errors, wonder if anyone has seen something similar?

timgilbert 2016-12-15T16:40:14.000079Z

2016-12-15 16:30:15,890 [XNIO-1 task-1] ERROR io.undertow.request: UT005071: Undertow request failed HttpServerExchange{ GET / request {X-Real-IP=[xxxx], Accept=[*/*], X-Amzn-Trace-Id=[Root=1-5852c517-5e570c000e2261a46ec0e6a9], Accept-Encoding=[gzip, deflate], User-Agent=[HTTPie/0.9.6], Connection=[upgrade], X-Forwarded-Proto=[http], X-Forwarded-Port=[80], X-Forwarded-For=[yyyy, zzzz], Host=[<http://app-qa.myapp.com|app-qa.myapp.com>]} response {Server=[undertow]}}
java.lang.ClassCastException: null

timgilbert 2016-12-15T16:41:21.000080Z

I'm seeing this specifically when requesting an insecure page

2016-12-15T16:43:51.000081Z

@timgilbert: is there a stack trace at all?

timgilbert 2016-12-15T16:44:21.000082Z

Sadly, no

timgilbert 2016-12-15T16:45:10.000083Z

I have immutant behind an AWS application load balancer which is termintating SSL and then forwarding to immutant

timgilbert 2016-12-15T16:46:03.000085Z

When I request a secure page from the load balancer, everything is kosher. But when I request an insecure page, I get the above error in the logs

timgilbert 2016-12-15T16:46:37.000086Z

Wondering if it's related to the Connection=[upgrade] bit or something

2016-12-15T16:49:35.000087Z

@timgilbert are you saying there is no stack trace or you can't access the logs with the stack trace?

timgilbert 2016-12-15T16:50:26.000088Z

There is no stack trace, like each http request outputs literally just the block of logs above

timgilbert 2016-12-15T16:52:13.000090Z

All of this is working fine over http running on localhost, BTW, so it seems like possibly some stuff added from the load-balancer to the EC2 instance might be throwing a spanner into the works

2016-12-15T16:52:48.000091Z

what version of immutant are you using?

timgilbert 2016-12-15T16:53:10.000092Z

[org.immutant/web "2.1.5"]

2016-12-15T16:54:13.000093Z

k, thanks. trying something locally to see if I can reproduce

timgilbert 2016-12-15T16:54:37.000094Z

Cool, thanks. Let me know if there's info I can provide.

2016-12-15T16:56:51.000095Z

well, that didn't work

2016-12-15T16:57:18.000096Z

I thought maybe the presence of a Connection: upgrade without an Upgrade: header was triggering it, but no

timgilbert 2016-12-15T16:57:30.000097Z

Hmm, yeah

timgilbert 2016-12-15T16:58:08.000098Z

I do have some code that's specifically looking for http connections and redirecting them, maybe it's an obscure bug in there

2016-12-15T16:58:30.000099Z

is this an uberjar, or are you running WildFly?

timgilbert 2016-12-15T16:58:33.000100Z

Anyways, I'll keep hacking. Thanks for looking anyways

timgilbert 2016-12-15T16:58:57.000101Z

This is an uberjar, running under a AWS Java SE Elastic Beanstalk environment

2016-12-15T16:59:16.000102Z

I think there is a way to register an error handler - possibly the default one is what gives you the log message

2016-12-15T16:59:19.000103Z

looking for that now

2016-12-15T17:20:23.000104Z

@timgilbert: there's no way to set an error handler for that error. It comes from: https://github.com/undertow-io/undertow/blob/1.3.23.Final/core/src/main/java/io/undertow/server/Connectors.java#L228

timgilbert 2016-12-15T17:20:48.000106Z

Hmm, interesting

2016-12-15T17:21:09.000107Z

line 202 is where your handler gets (eventually) called. If you could wrap your top-level handler in a try/catch, that might tell you something

2016-12-15T17:21:26.000108Z

but there are probably other handlers in the chain that get called before your code, so the issue could be there as well

timgilbert 2016-12-15T17:21:43.000109Z

I think I may have found a bug in my code actually, where some ring middleware was returning this:

(fn [request]
  (moved-permanently secure-url))
...instead of just (moved-permanently secure-url)

timgilbert 2016-12-15T17:22:23.000111Z

Which maybe would explain the ClassCastException

timgilbert 2016-12-15T17:23:02.000112Z

Will mess with it and let you know

2016-12-15T17:25:41.000113Z

cool, I'm here to help if that doesn't fix it

timgilbert 2016-12-15T17:58:57.000114Z

Ok, yes, that was indeed the problem. Thanks for your help!

timgilbert 2016-12-15T17:59:55.000115Z

I obviously need to set up some better exception logging somewhere. I do see stack traces for most things, but this one just gave me the one line.