Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

NullPointerException for some requests after 2.1.7 -> 2.1.9 upgrade #1316

Open
meetyourturik opened this issue Oct 11, 2022 · 0 comments
Open

Comments

@meetyourturik
Copy link

Hello,
after we've upgraded zuul version from 2.1.7 to 2.1.9 we've started having 502s returned for some requests

The main log message is the following:

logger_name: c.n.z.n.s.ClientResponseWriter
message: ClientResponseWriter caught exception in client connection pipeline: Channel: [id: 0x18e734fc, L:/10.255.0.12:8080 - R:/10.106.65.221:7742], active=true, open=true, registered=true, writable=true, id=18e734fc, Passport: CurrentPassport {start_ms=1665421851993, [+0=IN_REQ_HEADERS_RECEIVED, +25405=FILTERS_INBOUND_START, +605148=IN_REQ_LAST_CONTENT_RECEIVED, +8022162=FILTERS_INBOUND_END, +8472518=ORIGIN_CONN_ACQUIRE_START, +8474740=ORIGIN_CONN_ACQUIRE_END, +8501191=OUT_REQ_HEADERS_SENDING, +8525891=OUT_REQ_LAST_CONTENT_SENDING, +8581036=OUT_REQ_HEADERS_SENT, +8583789=OUT_REQ_LAST_CONTENT_SENT, +57036026=IN_RESP_HEADERS_RECEIVED, +57049009=FILTERS_OUTBOUND_START, +57203853=FILTERS_OUTBOUND_END, +57383477=NOW]}
stack_trace: j.l.NullPointerException: null
	at i.n.h.c.h.HttpUtil.isKeepAlive(HttpUtil.java:75)
	at c.n.z.n.s.ClientResponseWriter.buildHttpResponse(ClientResponseWriter.java:199)
	at c.n.z.n.s.ClientResponseWriter.channelRead(ClientResponseWriter.java:139)
	at i.n.c.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at i.n.c.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at i.n.c.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at c.n.z.n.f.BaseZuulFilterRunner.invokeNextStage(BaseZuulFilterRunner.java:151)
	at c.n.z.n.f.ZuulFilterChainRunner.runFilters(ZuulFilterChainRunner.java:88)
	at c.n.z.n.f.ZuulFilterChainRunner.filter(ZuulFilterChainRunner.java:56)
	at c.n.z.f.e.ProxyEndpoint.filterResponse(ProxyEndpoint.java:327)
	... 64 frames truncated

It seems to code from this line because nativeReq is null.
It's being retrieved from context by the CommonContextKeys.NETTY_HTTP_REQUEST key, and the only place where it's set seems to be here
I'm not sure what to make out of these discoveries, unfortunately

Also, if it helps to debug, these are other log entries for the same channel id:

logger_name: c.n.z.n.i.PassportLoggingHandler
message: Request processing took longer than threshold! toplevelid = 76982df9-c56a-463b-b4fb-f00db9d21c7d, Channel: [id: 0x18e734fc, L:/10.255.0.12:8080 - R:/10.106.65.221:7742], active=true, open=true, registered=true, writable=true, id=18e734fc, Passport: CurrentPassport {start_ms=1665421755721, [+0=IN_REQ_HEADERS_RECEIVED, +42807=FILTERS_INBOUND_START, +6862128=FILTERS_INBOUND_END, +6911049=ORIGIN_CONN_ACQUIRE_START, +6912093=ORIGIN_CONN_ACQUIRE_END, +6935320=OUT_REQ_HEADERS_SENDING, +7014311=OUT_REQ_HEADERS_SENT, +2879404595=IN_REQ_LAST_CONTENT_RECEIVED, +2879487068=OUT_REQ_LAST_CONTENT_SENDING, +2879529603=OUT_REQ_LAST_CONTENT_SENT, +3537669603=IN_RESP_HEADERS_RECEIVED, +3537685802=FILTERS_OUTBOUND_START, +3537838120=FILTERS_OUTBOUND_END, +3537861921=OUT_RESP_HEADERS_SENDING, +3537900333=OUT_RESP_HEADERS_SENT, +3537906991=IN_RESP_LAST_CONTENT_RECEIVED, +3537937795=OUT_RESP_LAST_CONTENT_SENDING, +3537962376=OUT_RESP_LAST_CONTENT_SENT, +3538291470=NOW]}

(there are several entries like this ↑ followed by the original NPE entry)

logger_name: c.n.z.n.s.ClientResponseWriter
message: Received complete event while still handling the request. With reason: CLOSE -- Channel: [id: 0x18e734fc, L:/10.255.0.12:8080 - R:/10.106.65.221:7742], active=true, open=true, registered=true, writable=true, id=18e734fc, Passport: CurrentPassport {start_ms=1665421851993, [+0=IN_REQ_HEADERS_RECEIVED, +25405=FILTERS_INBOUND_START, +605148=IN_REQ_LAST_CONTENT_RECEIVED, +8022162=FILTERS_INBOUND_END, +8472518=ORIGIN_CONN_ACQUIRE_START, +8474740=ORIGIN_CONN_ACQUIRE_END, +8501191=OUT_REQ_HEADERS_SENDING, +8525891=OUT_REQ_LAST_CONTENT_SENDING, +8581036=OUT_REQ_HEADERS_SENT, +8583789=OUT_REQ_LAST_CONTENT_SENT, +57036026=IN_RESP_HEADERS_RECEIVED, +57049009=FILTERS_OUTBOUND_START, +57203853=FILTERS_OUTBOUND_END, +57568295=SERVER_CH_CLOSE, +57582248=IN_REQ_CANCELLED, +57733681=ORIGIN_CH_CLOSE, +57774299=ORIGIN_CH_CLOSE, +58059284=NOW]}
logger_name: c.n.z.n.i.PassportLoggingHandler
message: Incorrect final state! toplevelid = 6426fec6-e938-4bc4-9dd5-d1b959101cbf, Channel: [id: 0x18e734fc, L:/10.255.0.12:8080 ! R:/10.106.65.221:7742], active=false, open=false, registered=true, writable=false, id=18e734fc, Passport: CurrentPassport {start_ms=1665421851993, [+0=IN_REQ_HEADERS_RECEIVED, +25405=FILTERS_INBOUND_START, +605148=IN_REQ_LAST_CONTENT_RECEIVED, +8022162=FILTERS_INBOUND_END, +8472518=ORIGIN_CONN_ACQUIRE_START, +8474740=ORIGIN_CONN_ACQUIRE_END, +8501191=OUT_REQ_HEADERS_SENDING, +8525891=OUT_REQ_LAST_CONTENT_SENDING, +8581036=OUT_REQ_HEADERS_SENT, +8583789=OUT_REQ_LAST_CONTENT_SENT, +57036026=IN_RESP_HEADERS_RECEIVED, +57049009=FILTERS_OUTBOUND_START, +57203853=FILTERS_OUTBOUND_END, +57568295=SERVER_CH_CLOSE, +57582248=IN_REQ_CANCELLED, +57733681=ORIGIN_CH_CLOSE, +57774299=ORIGIN_CH_CLOSE, +58078446=SERVER_CH_CLOSE, +58082086=SERVER_CH_CLOSE, +58140741=NOW]}

Also, all of the problem requests seems to be GraphQL ones

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant