如何找到 jetty 400 错误的原因？

Question

我有一个码头服务器（版本9.4.11。它与org.restlet-2.4.3结合使用）。客户端正在向我的服务器上的 api 发送一条 POST 消息（路由“/pos/v1/purchasable_items”），码头以 400 代码响应。我无法弄清楚原因。非常感谢您的帮助。

这里是jetty的完整日志：

12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Queued change org.eclipse.jetty.io.ManagedSelector$Accept@616b6a22 on org.eclipse.jetty.io.ManagedSelector@79c26be5 id=1 keys=0 selected=0 updates=0
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - wakeup on submit org.eclipse.jetty.io.ManagedSelector@79c26be5 id=1 keys=0 selected=0 updates=1
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e woken with none selected
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e woken up from select, 0/0/0 selected
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e processing 0 keys, 1 updates
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - updateable 1
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - update org.eclipse.jetty.io.ManagedSelector$Accept@616b6a22
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.util.thread.QueuedThreadPool     - queue org.eclipse.jetty.io.ManagedSelector$Accept@616b6a22
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - updates 0
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e waiting with 1 keys
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.util.thread.QueuedThreadPool     - run org.eclipse.jetty.io.ManagedSelector$Accept@616b6a22
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.IdleTimeout                   - SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=8/100000}{io=0/0,kio=0,kro=0}-><null> idle timeout check, elapsed: 7 ms, remaining: 99993 ms
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.PreEncodedHttpField         - HttpField encoders loaded: [org.eclipse.jetty.http.Http1FieldPreEncoder@1525e6cb]
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpChannel               - new HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0} -> SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=72/100000}{io=0/0,kio=0,kro=0}-><null>,null,HttpChannelState@7ae84ea1{s=IDLE a=NOT_ASYNC i=true r=IDLE w=false}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - New HTTP Connection HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=80/100000}{io=0/0,kio=0,kro=0}-><null>
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.AbstractEndPoint              - onOpen SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=81/100000}{io=0/0,kio=0,kro=0}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.AbstractConnection            - onOpen HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=81/100000}{io=0/0,kio=0,kro=0}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.AbstractConnection            - fillInterested HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=81/100000}{io=0/0,kio=0,kro=0}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.FillInterest                  - interested FillInterest@72454313{AC.ReadCB@30023a7c{HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=0/100000}{io=0/0,kio=0,kro=0}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}}}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ChannelEndPoint               - changeInterests p=false 0->1 for SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=0/100000}{io=0/1,kio=0,kro=0}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Queued change org.eclipse.jetty.io.ChannelEndPoint@528ccae5 on org.eclipse.jetty.io.ManagedSelector@79c26be5 id=1 keys=1 selected=0 updates=0
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - wakeup on submit org.eclipse.jetty.io.ManagedSelector@79c26be5 id=1 keys=1 selected=0 updates=1
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e woken with none selected
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e woken up from select, 0/0/1 selected
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e processing 0 keys, 1 updates
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - updateable 1
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - update org.eclipse.jetty.io.ChannelEndPoint@528ccae5
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Created SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=0/100000}{io=0/1,kio=0,kro=0}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.util.thread.QueuedThreadPool     - ran org.eclipse.jetty.io.ManagedSelector$Accept@616b6a22
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ChannelEndPoint               - Key interests updated 0 -> 1 on SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=1/100000}{io=1/1,kio=1,kro=0}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - updates 0
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e waiting with 1 keys
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e woken up from select, 1/1/1 selected
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e processing 1 keys, 0 updates
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - selected 1 channel=java.nio.channels.SocketChannel[connected local=/127.0.0.1:8182 remote=/127.0.0.1:50589], selector=sun.nio.ch.WindowsSelectorImpl@5c1f2b6e, interestOps=1, readyOps=1 SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=1/100000}{io=1/1,kio=1,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0} 
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ChannelEndPoint               - onSelected 1->0 r=true w=false for SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=1/100000}{io=1/0,kio=1,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ChannelEndPoint               - task CEP:SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=1/100000}{io=1/0,kio=1,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING
12:56:05 [36mDEBUG[0;39m o.eclipse.jetty.util.thread.ReservedThreadExecutor - ReservedThreadExecutor@77a9ea73{s=0/8,p=0} tryExecute EatWhatYouKill@218cf600/SelectorProducer@4aecb548/PRODUCING/p=false/QueuedThreadPool[qtp103099676]@6252d1c{STARTED,8<=8<=300,i=3,q=0}[ReservedThreadExecutor@77a9ea73{s=0/8,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-06-17T12:56:05.8701778+02:00
12:56:05 [36mDEBUG[0;39m o.eclipse.jetty.util.thread.ReservedThreadExecutor - ReservedThreadExecutor@77a9ea73{s=0/8,p=1} startReservedThread p=1
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.util.thread.QueuedThreadPool     - queue ReservedThreadExecutor@77a9ea73{s=0/8,p=1}@73ca3be9
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.util.thread.QueuedThreadPool     - run ReservedThreadExecutor@77a9ea73{s=0/8,p=1}@73ca3be9
12:56:05 [36mDEBUG[0;39m o.eclipse.jetty.util.thread.ReservedThreadExecutor - ReservedThreadExecutor@77a9ea73{s=1/8,p=1}@73ca3be9 started
12:56:05 [36mDEBUG[0;39m o.e.jetty.util.thread.strategy.EatWhatYouKill      - EatWhatYouKill@218cf600/SelectorProducer@4aecb548/PRODUCING/p=false/QueuedThreadPool[qtp103099676]@6252d1c{STARTED,8<=8<=300,i=2,q=0}[ReservedThreadExecutor@77a9ea73{s=0/8,p=1}][pc=0,pic=0,pec=0,epc=0]@2021-06-17T12:56:05.8721778+02:00 m=PRODUCE_EXECUTE_CONSUME t=CEP:SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=3/100000}{io=1/0,kio=1,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING/BLOCKING
12:56:05 [36mDEBUG[0;39m o.eclipse.jetty.util.thread.ReservedThreadExecutor - ReservedThreadExecutor@77a9ea73{s=1/8,p=0}@73ca3be9 waiting
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.util.thread.QueuedThreadPool     - queue CEP:SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=3/100000}{io=1/0,kio=1,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - updateable 0
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - updates 0
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ChannelEndPoint               - Key interests updated 1 -> 0 on SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=3/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ManagedSelector               - Selector sun.nio.ch.WindowsSelectorImpl@5c1f2b6e waiting with 1 keys
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.util.thread.QueuedThreadPool     - run CEP:SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=3/100000}{io=0/0,kio=1,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.FillInterest                  - fillable FillInterest@72454313{AC.ReadCB@30023a7c{HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=FI,flush=-,to=4/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}}}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=4/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0} onFillable enter HttpChannelState@7ae84ea1{s=IDLE a=NOT_ASYNC i=true r=IDLE w=false} null
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ChannelEndPoint               - filled 181 SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=6/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=3/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0} filled 181 HeapByteBuffer@25fdf14c[p=0,l=181,c=8192,r=181]={<<<POST /pos/v1/purc...00-continue\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}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=3/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=START,0 of -1},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=0,c=false,a=IDLE,uri=null,age=0} parse HeapByteBuffer@25fdf14c[p=0,l=181,c=8192,r=181]={<<<POST /pos/v1/purc...00-continue\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} {}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - parseNext s=START HeapByteBuffer@25fdf14c[p=0,l=181,c=8192,r=181]={<<<POST /pos/v1/purc...00-continue\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}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - START --> SPACE1
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - SPACE1 --> URI
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - URI --> SPACE2
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - SPACE2 --> REQUEST_VERSION
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - REQUEST_VERSION --> HEADER
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Content-Type: application/x-www-form-urlencoded --> IN_VALUE
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Content-Type: application/x-www-form-urlencoded --> FIELD
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Host --> VALUE
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Host --> IN_VALUE
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Host --> FIELD
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Content-Length --> VALUE
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Content-Length --> IN_VALUE
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Content-Length --> FIELD
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Expect --> VALUE
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Expect --> IN_VALUE
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER:Expect --> FIELD
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - HEADER --> CONTENT
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpChannel               - REQUEST for //127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05 on HttpChannelOverHttp@3b503229{r=1,c=false,a=IDLE,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=1}
POST //127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05 HTTP/1.1
Content-Type: application/x-www-form-urlencoded
Host: 127.0.0.1:8182
Content-Length: 228
Expect: 100-continue


12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=IDLE,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=2}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=13/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=IDLE,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=2} parsed true HttpParser{s=CONTENT,0 of 228}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - releaseRequestBuffer HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=IDLE,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=2}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=13/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=IDLE,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=2}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpChannel               - HttpChannelOverHttp@3b503229{r=1,c=false,a=IDLE,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=3} handle //127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05 
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpChannelState          - handling HttpChannelState@7ae84ea1{s=IDLE a=NOT_ASYNC i=true r=IDLE w=false}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpChannel               - HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=4} action DISPATCH
12:56:05 [36mTRACE[0;39m org.restlet.Component.ServerRouter                 - Call score for the "org.restlet.routing.VirtualHost@24386839" host: 1.0
12:56:05 [36mDEBUG[0;39m org.restlet.Component.ServerRouter                 - Default virtual host selected
12:56:05 [36mDEBUG[0;39m org.restlet.Component.ServerRouter                 - Base URI: "http://127.0.0.1:8182". Remaining part: "/pos/v1/purchasable_items?d=17.06.2021%2012:56:05"
12:56:05 [36mTRACE[0;39m org.restlet.VirtualHost                            - Call score for the "" URI pattern: 0.5
12:56:05 [36mDEBUG[0;39m org.restlet.VirtualHost                            - Selected route: "" -> de.sage.scheduler.access.server.AccessServerImpl@440e3ce6
12:56:05 [36mTRACE[0;39m org.restlet.VirtualHost                            - No characters were matched
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ChannelEndPoint               - filled 0 SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=47/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=36}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ChannelEndPoint               - filled 0 SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=47/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=36}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=36}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=47/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=36} filled 0 HeapByteBuffer@25fdf14c[p=0,l=0,c=8192,r=0]={<<<>>>POST /pos/v1/purc...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=36}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=48/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=37} parse HeapByteBuffer@25fdf14c[p=0,l=0,c=8192,r=0]={<<<>>>POST /pos/v1/purc...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00} {}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.http.HttpParser                  - parseNext s=CONTENT HeapByteBuffer@25fdf14c[p=0,l=0,c=8192,r=0]={<<<>>>POST /pos/v1/purc...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=37}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=48/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=37} parsed false HttpParser{s=CONTENT,0 of 228}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - releaseRequestBuffer HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=37}<-SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=-,to=48/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=START}]=>HttpChannelOverHttp@3b503229{r=1,c=false,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=37}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpChannel               - sendResponse info=HTTP/1.1{s=100,h=-1,cl=-1} content=null complete=false committing=true callback=Blocker@5a2856fc{null}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpChannel               - COMMIT for /pos/v1/purchasable_items on HttpChannelOverHttp@3b503229{r=1,c=true,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=37}
100 null HTTP/1.1
null
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - org.eclipse.jetty.server.HttpConnection$SendCallback@364501c7[PROCESSING][i=HTTP/1.1{s=100,h=-1,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$Commit100Callback@d25f545] generate: NEED_HEADER (null,null,false)@START
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - org.eclipse.jetty.server.HttpConnection$SendCallback@364501c7[PROCESSING][i=HTTP/1.1{s=100,h=-1,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$Commit100Callback@d25f545] generate: FLUSH ([p=0,l=25,c=8192,r=25],null,false)@COMPLETING_1XX
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.WriteFlusher                  - write: WriteFlusher@786527a2{IDLE}->null [HeapByteBuffer@25fdf14c[p=0,l=25,c=8192,r=25]={<<<HTTP/1.1 100 Continue\r\n\r\n>>>items?d=17.06.202...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}]
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.WriteFlusher                  - update WriteFlusher@786527a2{WRITING}->null:IDLE-->WRITING
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.ChannelEndPoint               - flushed 25 SocketChannelEndPoint@54fedde4{/127.0.0.1:50589<->/127.0.0.1:8182,OPEN,fill=-,flush=W,to=55/100000}{io=0/0,kio=0,kro=1}->HttpConnection@30023a7c[p=HttpParser{s=CONTENT,0 of 228},g=HttpGenerator@7f9bfe40{s=COMPLETING_1XX}]=>HttpChannelOverHttp@3b503229{r=1,c=true,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=44}
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.WriteFlusher                  - Flushed=true written=25 remaining=0 WriteFlusher@786527a2{WRITING}->null
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.io.WriteFlusher                  - update WriteFlusher@786527a2{IDLE}->null:WRITING-->IDLE
12:56:05 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpConnection            - org.eclipse.jetty.server.HttpConnection$SendCallback@364501c7[PROCESSING][i=HTTP/1.1{s=100,h=-1,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$Commit100Callback@d25f545] generate: DONE ([p=25,l=25,c=8192,r=0],null,false)@START
12:56:09 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpChannel               - sendResponse info=null content=DirectByteBuffer@3b173fda[p=0,l=84,c=32768,r=84]={<<<{"DESC":"The requ...formed syntax"}>>>\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} complete=false committing=true callback=Blocker@5a2856fc{null}
12:56:09 [36mDEBUG[0;39m org.eclipse.jetty.server.HttpChannel               - COMMIT for /pos/v1/purchasable_items on HttpChannelOverHttp@3b503229{r=1,c=true,a=DISPATCHED,uri=//127.0.0.1:8182/pos/v1/purchasable_items?d=17.06.2021%2012:56:05,age=3888}
400 null HTTP/1.1
Content-Type: application/json;charset=utf-8
Date: Thu, 17 Jun 2021 10:56:09 GMT
Accept-Ranges: bytes
Server: Restlet-Framework/2.4.3
Access-Control-Allow-Credentials: true
Access-Control-Allow-Headers: Authorization, Content-Type
Access-Control-Allow-Methods: DELETE, POST, GET, OPTIONS, PUT

我也尝试过用Wireshark调试它，但没有成功。这是通信的概述（服务器端口 8182 im）：

这是来自 Wireshark 的 POST 请求的详细信息：

如果有人给我提示，我会很高兴。

Answer 1

您的客户正在发送 POST 和 Expect: 100-Continue header（一个足够正常的概念）。

很难从你的 wireshark 中分辨出来，但看起来你的客户端没有正确处理 HTTP/1.1 100 Continue 响应。

您的客户端应等待发送请求的 body，直到收到 HTTP/1.1 100 Continue 响应。

并且当它发送请求body时，它应该只包含请求body，它不应该再次发送请求headers. （你在码头上的日志和你的 wireshark 似乎都显示了）。

这些 header 不符合 Content-Type: application/x-www-form-urlencoded 并导致 400 错误请求响应。

建议，同时升级您的 Restlet 版本和 Jetty 版本。

根据请求发送的 header 判断，您有一个非常旧的 restlet 版本（我希望看到一些 header，但没有看到）。

您的 Jetty 版本 9.4.11 很旧并且缺少许多 important fixes（其中一个是 400 Bad Request 周围更清晰的错误消息，这可以帮助您自己解决这个问题）。你落后版本 9.4.42.v20210604 3,081 次更新（是的，三千八十一次更新）。

Answer 2

问题原来是用户代理黑名单阻止了请求，因为它没有用户代理。跟码头没关系。

如何找到 jetty 400 错误的原因？

How to find the reason for a jetty 400 error?

jetty

restlet

jetty-9