| [jetty-users] HTTP 400 status code returned after Jetty server upgraded from 9.0 to 9.2 |
|
Hi,
I have upgraded the embedded Jetty server from 9.0 to latest 9.2 version. The HTTP GET/POST requests return 400 code. I also saw this warning log: WARN HttpParser:59 - badMessage: java.lang.ArrayIndexOutOfBoundsException:
0 for HttpChannelOverHttp@2e70eea7{r=0,c=false,a=IDLE,uri=-} Anyone has got the insight on how to fix the issue?
The detailed debugging messages are: 015-08-12 15:51:55 DEBUG SelectorManager:89 - Queued change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Accept@55c4b148 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Selector loop woken up from select, 0/0 selected 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Running change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Accept@55c4b148 2015-08-12 15:51:55 DEBUG AbstractEndPoint:89 - onOpen SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,-,-,3/30000,null}{io=0,kio=0,kro=0} 2015-08-12 15:51:55 DEBUG IdleTimeout:89 - SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,-,-,3/30000,null}{io=0,kio=0,kro=0} idle timeout check, elapsed: 3 ms, remaining: 29997 ms 2015-08-12 15:51:55 DEBUG HttpChannel:89 - new HttpChannelOverHttp@2e70eea7{r=0,c=false,a=IDLE,uri=-} -> SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,-,-,29/30000,null}{io=0,kio=0,kro=0},null,HttpChannelState@78442dc2{s=IDLE i=true a=null} 2015-08-12 15:51:55 DEBUG HttpConnection:89 - New HTTP Connection HttpConnection@45d14aaa{IDLE} 2015-08-12 15:51:55 DEBUG AbstractConnection:89 - onOpen HttpConnection@45d14aaa{IDLE} 2015-08-12 15:51:55 DEBUG AbstractConnection:89 - fillInterested HttpConnection@45d14aaa{IDLE} 2015-08-12 15:51:55 DEBUG AbstractConnection:89 - IDLE-->FILL_INTERESTED HttpConnection@45d14aaa{FILL_INTERESTED} 2015-08-12 15:51:55 DEBUG SelectChannelEndPoint:89 - Local interests updating 0 -> 1 for SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,R,-,0/30000,HttpConnection}{io=1,kio=0,kro=0} 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@320dce4f 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Created SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,R,-,1/30000,HttpConnection}{io=1,kio=0,kro=0} 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@320dce4f 2015-08-12 15:51:55 DEBUG SelectChannelEndPoint:89 - Key interests updated 0 -> 1 on SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,R,-,2/30000,HttpConnection}{io=1,kio=1,kro=0} 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Selector loop waiting on select 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Selector loop woken up from select, 1/1 selected 2015-08-12 15:51:55 DEBUG SelectChannelEndPoint:89 - Key interests updated 1 -> 0 on SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,R,-,2/30000,HttpConnection}{io=1,kio=0,kro=1} 2015-08-12 15:51:55 DEBUG SelectChannelEndPoint:89 - Local interests updating 1 -> 0 for SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,R,-,3/30000,HttpConnection}{io=0,kio=0,kro=1} 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Queued change org.eclipse.jetty.io.SelectChannelEndPoint$1@320dce4f 2015-08-12 15:51:55 DEBUG AbstractConnection:89 - FILL_INTERESTED-->FILLING HttpConnection@45d14aaa{FILLING} 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Running change org.eclipse.jetty.io.SelectChannelEndPoint$1@320dce4f 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Selector loop waiting on select 2015-08-12 15:51:55 DEBUG HttpConnection:89 - HttpConnection@45d14aaa{FILLING} onFillable HttpChannelState@78442dc2{s=IDLE i=true a=null} 2015-08-12 15:51:55 DEBUG ChannelEndPoint:89 - filled 394 SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,-,-,4/30000,HttpConnection}{io=0,kio=0,kro=1} 2015-08-12 15:51:55 DEBUG HttpParser:89 - parseNext s=START HeapByteBuffer@2c5c9e4a[p=0,l=394,c=8192,r=394]={<<<POST /mock/127.0....d":"127.0.0.1"}>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 2015-08-12 15:51:55 DEBUG HttpParser:89 - START --> SPACE1 2015-08-12 15:51:55 DEBUG HttpParser:89 - SPACE1 --> URI 2015-08-12 15:51:55 DEBUG HttpParser:89 - URI --> SPACE2 2015-08-12 15:51:55 DEBUG HttpParser:89 - SPACE2 --> REQUEST_VERSION 2015-08-12 15:51:55 DEBUG HttpParser:89 - REQUEST_VERSION --> HEADER 2015-08-12 15:51:55 WARN HttpParser:59 - badMessage: java.lang.ArrayIndexOutOfBoundsException: 0 for HttpChannelOverHttp@2e70eea7{r=0,c=false,a=IDLE,uri=-} 2015-08-12 15:51:55 DEBUG HttpParser:105 - java.lang.ArrayIndexOutOfBoundsException: 0 at org.eclipse.jetty.util.ArrayTernaryTrie.getBest(ArrayTernaryTrie.java:374) at org.eclipse.jetty.util.ArrayTernaryTrie.getBest(ArrayTernaryTrie.java:357) at org.eclipse.jetty.http.HttpParser.parseHeaders(HttpParser.java:1047) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1257) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:250) at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) at java.lang.Thread.run(Thread.java:744) 2015-08-12 15:51:55 DEBUG HttpParser:89 - HEADER --> CLOSED 2015-08-12 15:51:55 DEBUG HttpChannelState:89 - HttpChannelState@78442dc2{s=IDLE i=true a=null} handling IDLE 2015-08-12 15:51:55 DEBUG HttpConnection:89 - org.eclipse.jetty.server.HttpConnection$SendCallback@4652a2dd[PROCESSING][i=ResponseInfo{HTTP/1.1 400 null,0,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@5b427f3c] generate: NEED_HEADER (null,null,true)@START 2015-08-12 15:51:55 DEBUG HttpConnection:89 - org.eclipse.jetty.server.HttpConnection$SendCallback@4652a2dd[PROCESSING][i=ResponseInfo{HTTP/1.1 400 null,0,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@5b427f3c] generate: FLUSH ([p=0,l=99,c=8192,r=99],null,true)@COMPLETING 2015-08-12 15:51:55 DEBUG WriteFlusher:89 - write: WriteFlusher@5bd3465a{IDLE} [HeapByteBuffer@4e26e633[p=0,l=99,c=8192,r=99]={<<<HTTP/1.1 400 Bad ....v20150730)\r\n\r\n>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}] 2015-08-12 15:51:55 DEBUG WriteFlusher:89 - update WriteFlusher@5bd3465a{WRITING}:IDLE-->WRITING 2015-08-12 15:51:55 DEBUG ChannelEndPoint:89 - flushed 99 SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,-,W,10/30000,HttpConnection}{io=0,kio=0,kro=1} 2015-08-12 15:51:55 DEBUG WriteFlusher:89 - update WriteFlusher@5bd3465a{IDLE}:WRITING-->IDLE 2015-08-12 15:51:55 DEBUG HttpConnection:89 - org.eclipse.jetty.server.HttpConnection$SendCallback@4652a2dd[PROCESSING][i=ResponseInfo{HTTP/1.1 400 null,0,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@5b427f3c] generate: SHUTDOWN_OUT ([p=99,l=99,c=8192,r=0],null,true)@END 2015-08-12 15:51:55 DEBUG HttpConnection:89 - org.eclipse.jetty.server.HttpConnection$SendCallback@4652a2dd[PROCESSING][i=ResponseInfo{HTTP/1.1 400 null,0,false},cb=org.eclipse.jetty.server.HttpChannel$CommitCallback@5b427f3c] generate: DONE ([p=99,l=99,c=8192,r=0],null,true)@END 2015-08-12 15:51:55 DEBUG ChannelEndPoint:89 - oshut SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,out,-,-,1/30000,HttpConnection}{io=0,kio=0,kro=1} 2015-08-12 15:51:55 DEBUG HttpChannelState:89 - HttpChannelState@78442dc2{s=DISPATCHED i=true a=null} unhandle DISPATCHED 2015-08-12 15:51:55 DEBUG ChannelEndPoint:89 - filled -1 SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,OSHUT,-,-,1/30000,HttpConnection}{io=0,kio=0,kro=1} 2015-08-12 15:51:55 DEBUG ChannelEndPoint:89 - ishut SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,Open,in,OSHUT,-,-,2/30000,HttpConnection}{io=0,kio=0,kro=1} 2015-08-12 15:51:55 DEBUG AbstractEndPoint:89 - onClose SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,CLOSED,ISHUT,OSHUT,-,-,2/30000,HttpConnection}{io=0,kio=0,kro=1} 2015-08-12 15:51:55 DEBUG ChannelEndPoint:89 - close SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,CLOSED,ISHUT,OSHUT,-,-,3/30000,HttpConnection}{io=0,kio=0,kro=1} 2015-08-12 15:51:55 DEBUG SelectorManager:89 - Destroyed SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,CLOSED,ISHUT,OSHUT,-,-,3/30000,HttpConnection}{io=0,kio=-1,kro=-1} 2015-08-12 15:51:55 DEBUG AbstractConnection:89 - onClose HttpConnection@45d14aaa{FILLING} 2015-08-12 15:51:55 DEBUG AbstractEndPoint:89 - onClose SelectChannelEndPoint@57f83f44{/127.0.0.1:60062<->2013,CLOSED,ISHUT,OSHUT,-,-,4/30000,HttpConnection}{io=0,kio=-1,kro=-1} 2015-08-12 15:51:55 DEBUG HttpParser:89 - atEOF HttpParser{s=CLOSED,0 of 0} 2015-08-12 15:51:55 DEBUG HttpParser:89 - parseNext s=CLOSED HeapByteBuffer@4e26e633[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 400 Bad ...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} 2015-08-12 15:51:55 DEBUG AbstractConnection:89 - FILLING-->IDLE HttpConnection@45d14aaa{IDLE} |