How to find the reason for a jetty 400 error?
I have a jetty server (version 9.4.11. It is used in combination with org.restlet-2.4.3). A client is sending a POST message to an api on my server (route "/pos/v1/purchasable_items") and jetty responds with 400 code. I cannot figure out the reason. I would really appreciate some help.
Here is the full log of 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$1@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$1@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
I have also tried to debug it with Wireshark without any success. This is the overview of the communication (Port 8182 im by server):
This is the POST request in detail from Wireshark:
I would be happy about anyone giving me a hint.
Solution
The problem turned out to be a user-agent black list which blocked the request because it had no user-agent. It had nothing to do with jetty.
- Launch Jetty 9 Programmatically
- Avoid 301 re-directs with HTTP POST requests in Jetty 12
- How to add servlet Filter with embedded jetty
- Why use server.join() in Embedded Jetty
- Maven Jetty - do not reload the whole application when modifying only static files
- Geoserver and moving to HTTPS
- Spring6, Jersey3, Jetty12, SEVERE: Spring context lookup failed, skipping spring component provider initialization
- How to POST with Curl to configSubmit Jenkins page
- Error when using selfhosted (Jetty) Metabase with ssl inside docker container
- Serving static html files using DefaultServlet on embedded Jetty
- Turn off WICKET AJAX DEBUG
- java.lang.ClassNotFoundException: jakarta.servlet.http.HttpSessionContext with Spring Boot 3 and Jetty server
- How do I create an embedded WebSocket server Jetty 9?
- Jetty embedded and JSP compilation to 1.7?
- Deploying Jakarta EE Application on Jetty 12: from jetty-ee10-maven-plugin to deployment on Jetty, ClassNotFoundException and CDIProvider Issues
- GAE on java 21 throws NullPointerException at CookieCache.parseCookies()
- Multiple HttpSession Objects for One Logged-In User
- How to control VM arguments for maven-jetty-plugin?
- Jetty tmp Multipart files not being deleted after upload
- Jetty Server 9 to 12 migration
- Setting WebSocket session idle timeout using Spring's Websocket API & Jetty 10
- is it possible to debug camel rest dsl component with jetty and unirest
- Missing Jetty HttpConnection class in Ktor fat JAR
- Jetty 11: Set idle timeout for WebSockets programmatically and via configuration file
- How do I change the default jetty port using dockerized jetty
- Profiling jetty with visualvm is super slow
- How do you set in Jetty 12 a max request size programmatically
- Custom Jetty WebSocketPolicy with Spring Web Sockets and STOMP
- Jetty set extraClasspath doesn't work after updating the jetty-maven-plugin
- Missing jetty-servlet 12.0.0 dependency