search

jetty / jetty.project

Eclipse Jetty® - Web Container & Clients - supports HTTP/2, HTTP/1.1, HTTP/1.0, websocket, servlets, and more
https://eclipse.dev/jetty
Other
3.84k stars 1.91k forks source link

SPNEGOAuthentication does not work for proxy authentication authorization in CometD #11643

Open richardydhan opened 5 months ago

richardydhan commented 5 months ago

Jetty version(s)

jetty-client:12.0.0 cometd-java-client-http-jetty:8.0.0.beta0

Jetty Environment

core

Java version/vendor (use: java -version) Oracle jdk 17

OS type/version k8s container with Red Hat Enterprise Linux 9

Description

Try to use SPNEGOAuthentication for proxy auth, but got "407 Proxy Authentication Required", seems not work. code:

    String uriString = "http://" + this.proxyHost + ":" +  this.proxyPort
    log.info("The proxy uri is: $uriString")
    String cachePath = System.getenv("KRB5CCNAME")
    log.info("The ticket cache path is: $cachePath")

    URI proxyUri = new URI(uriString)
    SPNEGOAuthentication auth = new SPNEGOAuthentication(proxyUri);
    auth.setUseTicketCache(true)
    auth.setTicketCachePath(Path.of(cachePath, ""))
    auth.setRenewTGT(true) //TODO: double check
    auth.setUserName("idi_kfk_t")
    auth.setServiceName("HTTP")

    return auth
@Override
Collection<? extends ProxyConfiguration.Proxy> proxies() {
    List<ProxyConfiguration.Proxy> proxyList = new ArrayList<>();
    Origin.Address address = new Origin.Address(this.proxyHost, this.proxyPort);
    ProxyConfiguration.Proxy proxy = new HttpProxy(address, false);
    proxyList.add(proxy);

    return proxyList;
}
    httpClient = new HttpClient();
    AuthenticationStore authStore = httpClient.getAuthenticationStore();
    authStore.addAuthentication(parameters.getKerberosAuthentication());
    parameters.proxies().forEach({proxy -> httpClient.getProxyConfiguration().addProxy(proxy)});

below the logs:

2024-04-10T14:25:21.647Z INFO 1 --- [ main] n.j.i.streaming.salesforce.EmpConnector : EmpConnector connecting 2024-04-10T14:25:21.654Z INFO 1 --- [ main] n.j.i.streaming.salesforce.EmpConnector : httpClient starting ... 2024-04-10T14:25:22.051Z DEBUG 1 --- [ main] o.cometd.client.BayeuxClient.7f584d0c : State updated: DISCONNECTED -> HANDSHAKING 2024-04-10T14:25:22.137Z DEBUG 1 --- [ main] o.cometd.client.BayeuxClient.7f584d0c : Using initial transport long-polling from [long-polling] 2024-04-10T14:25:22.138Z DEBUG 1 --- [ main] o.cometd.client.BayeuxClient.7f584d0c : Handshaking on transport net.xxx.salesforce.EmpConnector$1@4603c412: {supportedConnectionTypes=[long-polling], channel=/meta/handshake, id=1, version=1.0} 2024-04-10T14:25:22.147Z INFO 1 --- [ntainer#1-0-C-1] o.a.k.c.c.internals.ConsumerCoordinator : [Consumer clientId=consumer-idi-109004-2, groupId=idi-109004] Successfully joined group with generation Generation{generationId=1766, memberId='consumer-idi-109004-2-dd23d545-b030-4b47-aa38-205d605f0333', protocol='range'} 2024-04-10T14:25:22.147Z INFO 1 --- [ntainer#0-0-C-1] o.a.k.c.c.internals.ConsumerCoordinator : [Consumer clientId=consumer-idi-109004-1, groupId=idi-109004] Successfully joined group with generation Generation{generationId=1766, memberId='consumer-idi-109004-1-b811c425-e2b3-443c-ba0a-f6ad61c7e159', protocol='range'} 2024-04-10T14:25:22.148Z DEBUG 1 --- [ main] o.cometd.client.BayeuxClient.7f584d0c : Sending messages [{ext={replay=true}, supportedConnectionTypes=[long-polling], channel=/meta/handshake, id=1, version=1.0}] 2024-04-10T14:25:22.152Z DEBUG 1 --- [ main] o.e.jetty.http.PreEncodedHttpField : loaded 2 HttpFieldPreEncoders 2024-04-10T14:25:22.244Z INFO 1 --- [ main] n.j.i.streaming.salesforce.EmpConnector : httpTransport customize ... 2024-04-10T14:25:22.342Z DEBUG 1 --- [ main] o.c.c.h.jetty.JettyHttpClientTransport : Started waiting for message replies, 1800000 ms, task@6ca30886 2024-04-10T14:25:22.350Z DEBUG 1 --- [ main] org.eclipse.jetty.client.HttpClient : Created HttpDestination[Origin@f3b805d0[https://xxx.sandbox.my.salesforce.com,tag=null,protocol=Protocol@7f4624a[proto=[http/1.1],nego=false]]]@3dc4ed6f(via Origin@1130c1d7[http://server-proxy.xxx.net:11443,tag=null,protocol=Protocol@7f4624a[proto=[http/1.1],nego=false]]),state=STARTED,queue=0,pool=DuplexConnectionPool@2823b7c5[s=STARTED,c=0/0/64,a=0,i=0,q=0,p=ConcurrentPool@40f15786[strategy=FIRST,inUse=0,size=0,max=64,leaked=0,terminated=false]],stale=false,idle=-1; existing: 'null' 2024-04-10T14:25:22.434Z DEBUG 1 --- [ main] org.eclipse.jetty.client.HttpClient : Resolved HttpDestination[Origin@f3b805d0[https://xxx.sandbox.my.salesforce.com,tag=null,protocol=Protocol@7f4624a[proto=[http/1.1],nego=false]]]@3dc4ed6f(via Origin@1130c1d7[http://server-proxy.xxx.net:11443,tag=null,protocol=Protocol@7f4624a[proto=[http/1.1],nego=false]]),state=STARTED,queue=0,pool=DuplexConnectionPool@2823b7c5[s=STARTED,c=0/0/64,a=0,i=0,q=0,p=ConcurrentPool@40f15786[strategy=FIRST,inUse=0,size=0,max=64,leaked=0,terminated=false]],stale=false,idle=-1 for HttpRequest[POST /cometd/58.0/handshake HTTP/1.1]@72ea6fcb 2024-04-10T14:25:22.436Z DEBUG 1 --- [ main] o.e.j.client.transport.HttpConversation : Exchanges in conversation 1, override=null, listeners=org.eclipse.jetty.client.transport.ResponseListeners@77acc95a 2024-04-10T14:25:22.437Z DEBUG 1 --- [ main] o.e.j.client.transport.HttpDestination : Queued HttpRequest[POST /cometd/58.0/handshake HTTP/1.1]@72ea6fcb for HttpDestination[Origin@f3b805d0[https://xxx.sandbox.my.salesforce.com,tag=null,protocol=Protocol@7f4624a[proto=[http/1.1],nego=false]]]@3dc4ed6f(via Origin@1130c1d7[http://server-proxy.xxx.net:11443,tag=null,protocol=Protocol@7f4624a[proto=[http/1.1],nego=false]]),state=STARTED,queue=1,pool=DuplexConnectionPool@2823b7c5[s=STARTED,c=0/0/64,a=0,i=0,q=1,p=ConcurrentPool@40f15786[strategy=FIRST,inUse=0,size=0,max=64,leaked=0,terminated=false]],stale=false,idle=-1 2024-04-10T14:25:22.437Z DEBUG 1 --- [ main] o.e.jetty.client.AbstractConnectionPool : Acquiring create=true on DuplexConnectionPool@2823b7c5[s=STARTED,c=0/0/64,a=0,i=0,q=1,p=ConcurrentPool@40f15786[strategy=FIRST,inUse=0,size=0,max=64,leaked=0,terminated=false]] 2024-04-10T14:25:22.437Z DEBUG 1 --- [ main] o.e.jetty.client.AbstractConnectionPool : Try creating connection 0/64 with 0 pending 2024-04-10T14:25:22.437Z DEBUG 1 --- [ main] o.e.jetty.client.AbstractConnectionPool : Try creating(true) connection, pending/demand/supply: 0/2/0, result=true 2024-04-10T14:25:22.438Z DEBUG 1 --- [ main] o.e.jetty.client.AbstractConnectionPool : Creating connection 0/64 at ConcurrentEntry@27aa7294{terminated=false,multiplex=-1,pooled=null} 2024-04-10T14:25:22.441Z DEBUG 1 --- [ main] o.cometd.client.BayeuxClient.7f584d0c : Sent handshake {ext={replay=true}, supportedConnectionTypes=[long-polling], channel=/meta/handshake, id=1, version=1.0} 2024-04-10T14:25:22.441Z DEBUG 1 --- [ main] o.cometd.client.BayeuxClient.7f584d0c : Notifying threads in waitFor() 2024-04-10T14:25:22.540Z DEBUG 1 --- [ent@3c5044fa-39] org.eclipse.jetty.client.HttpClient : Created HttpDestination[Origin@1130c1d7[http://server-proxy.xxx.net:11443,tag=null,protocol=Protocol@7f4624a[proto=[http/1.1],nego=false]]]@408c5165,state=STARTED,queue=0,pool=DuplexConnectionPool@6799671d[s=STARTED,c=0/0/64,a=0,i=0,q=0,p=ConcurrentPool@6ccfa58e[strategy=FIRST,inUse=0,size=0,max=64,leaked=0,terminated=false]],stale=false,idle=-1; existing: 'null' 2024-04-10T14:25:22.741Z DEBUG 1 --- [ent@3c5044fa-39] o.e.j.c.t.HttpClientTransportOverHTTP : Created HttpConnectionOverHTTP@103c82d3::SocketChannelEndPoint@11a1b697[{l=/100.127.97.210:39894,r=server-proxy.xxx.net/155.180.102.45:11443,OPEN,fill=-,flush=-,to=204/30000}{io=0/0,kio=0,kro=8}]->[] 2024-04-10T14:25:22.743Z DEBUG 1 --- [ent@3c5044fa-39] o.e.j.client.transport.HttpDestination : Stale check done with result false on HttpDestination[Origin@1130c1d7[http://server-proxy.xxx.net:11443,tag=null,protocol=Protocol@7f4624a[proto=[http/1.1],nego=false]]]@408c5165,state=STARTED,queue=0,pool=DuplexConnectionPool@6799671d[s=STARTED,c=0/0/64,a=0,i=0,q=0,p=ConcurrentPool@6ccfa58e[strategy=FIRST,inUse=0,size=0,max=64,leaked=0,terminated=false]],stale=false,idle=-1 2024-04-10T14:25:22.744Z DEBUG 1 --- [ent@3c5044fa-39] o.e.j.client.transport.HttpConversation : Exchanges in conversation 1, override=null, listeners=org.eclipse.jetty.client.transport.ResponseListeners@1905a6c5 2024-04-10T14:25:22.745Z DEBUG 1 --- [ent@3c5044fa-39] o.e.j.client.transport.HttpConnection : Normalizing true TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.746Z DEBUG 1 --- [ent@3c5044fa-39] o.e.jetty.client.transport.HttpChannel : HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[PENDING/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]} associated true to HttpChannelOverHTTP@6c77a6c2(exchange=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[PENDING/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]})[send=HttpSenderOverHTTP@1dcc6c7b(req=QUEUED,failure=null)[HttpGenerator@5bac2c8f{s=START}],recv=HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[PENDING/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}]] 2024-04-10T14:25:22.747Z DEBUG 1 --- [ent@3c5044fa-39] o.e.jetty.client.transport.HttpSender : Request begin TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.747Z DEBUG 1 --- [ent@3c5044fa-39] o.e.jetty.client.transport.HttpSender : Request headers TunnelRequest[CONNECT .sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca Accept-Encoding: gzip User-Agent: Jetty/12.0.8 Host: xxx.sandbox.my.salesforce.com:443 2024-04-10T14:25:22.748Z DEBUG 1 --- [ent@3c5044fa-39] o.e.jetty.client.transport.HttpSender : Content EOF for TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.750Z DEBUG 1 --- [ent@3c5044fa-39] o.e.j.c.t.internal.HttpSenderOverHTTP : Sending headers with content HeapByteBufferR@2d1e7930[p=0,l=0,c=0,r=0]={<<<>>>} last=true for TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.834Z DEBUG 1 --- [ent@3c5044fa-39] o.e.j.c.t.internal.HttpSenderOverHTTP : Generated headers (-1 bytes), chunk (-1 bytes), content (0 bytes) - NEED_HEADER/HttpGenerator@5bac2c8f{s=START} for TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.837Z DEBUG 1 --- [ent@3c5044fa-39] org.eclipse.jetty.http.HttpGenerator : generateHeaders CONNECT{u=xxx.sandbox.my.salesforce.com:443,HTTP/1.1,h=3,cl=0,p=null} last=true content=HeapByteBufferR@2d1e7930[p=0,l=0,c=0,r=0]={<<<>>>} 2024-04-10T14:25:22.838Z DEBUG 1 --- [ent@3c5044fa-39] org.eclipse.jetty.http.HttpGenerator : Accept-Encoding: gzip User-Agent: Jetty/12.0.8 Host: xxx.sandbox.my.salesforce.com:443

2024-04-10T14:25:22.839Z DEBUG 1 --- [ent@3c5044fa-39] org.eclipse.jetty.http.HttpGenerator : endOfContent NO_CONTENT content-Length 0 2024-04-10T14:25:22.839Z DEBUG 1 --- [ent@3c5044fa-39] o.e.j.c.t.internal.HttpSenderOverHTTP : Generated headers (166 bytes), chunk (-1 bytes), content (0 bytes) - FLUSH/HttpGenerator@5bac2c8f{s=COMPLETING} for TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.840Z DEBUG 1 --- [ent@3c5044fa-39] o.e.j.c.t.internal.HttpSenderOverHTTP : Generated headers (-1 bytes), chunk (-1 bytes), content (-1 bytes) - DONE/HttpGenerator@5bac2c8f{s=END} for TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.841Z DEBUG 1 --- [ent@3c5044fa-39] o.e.jetty.client.transport.HttpSender : Request committed TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.841Z DEBUG 1 --- [ent@3c5044fa-39] o.e.jetty.client.transport.HttpSender : Request success TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.841Z DEBUG 1 --- [ent@3c5044fa-39] o.e.jetty.client.transport.HttpExchange : Terminated request for HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]}, result: null 2024-04-10T14:25:22.841Z DEBUG 1 --- [ent@3c5044fa-39] o.e.jetty.client.transport.HttpSender : Terminating request TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca 2024-04-10T14:25:22.934Z DEBUG 1 --- [ent@3c5044fa-41] o.e.j.c.t.internal.HttpReceiverOverHTTP : Acquired Buffer@51fd9e60[rc=1,DirectByteBuffer@5f3a6a2f[p=0,l=0,c=16384,r=0]={<<<>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00}] in HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}] 2024-04-10T14:25:22.935Z DEBUG 1 --- [ent@3c5044fa-41] o.e.j.c.t.internal.HttpReceiverOverHTTP : Parsing DirectByteBuffer@5f3a6a2f[p=0,l=0,c=16384,r=0]={<<<>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00} in HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}] 2024-04-10T14:25:22.935Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : parseNext s=START DirectByteBuffer@5f3a6a2f[p=0,l=0,c=16384,r=0]={<<<>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00} 2024-04-10T14:25:22.935Z DEBUG 1 --- [ent@3c5044fa-41] o.e.j.c.t.internal.HttpReceiverOverHTTP : Parse result=false on HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}] 2024-04-10T14:25:22.935Z DEBUG 1 --- [ent@3c5044fa-41] o.e.j.c.t.internal.HttpReceiverOverHTTP : Parse complete=false, Buffer@51fd9e60[rc=1,DirectByteBuffer@5f3a6a2f[p=0,l=0,c=16384,r=0]={<<<>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00}] HttpParser{s=START,0 of -1} in HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}] 2024-04-10T14:25:22.935Z DEBUG 1 --- [ent@3c5044fa-41] o.e.j.c.t.internal.HttpReceiverOverHTTP : Parser willing to advance in HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}] 2024-04-10T14:25:22.935Z DEBUG 1 --- [ent@3c5044fa-41] o.e.j.c.t.internal.HttpReceiverOverHTTP : Read 831 bytes in Buffer@51fd9e60[rc=1,DirectByteBuffer@5f3a6a2f[p=0,l=831,c=16384,r=831]={<<<HTTP/1.1 407 Proxy Authen... >>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00}] from SocketChannelEndPoint@11a1b697[{l=/100.127.97.210:39894,r=server-proxy.xxx.net/155.180.102.45:11443,OPEN,fill=-,flush=-,to=0/10000}{io=0/0,kio=0,kro=1}]->[HttpConnectionOverHTTP@103c82d3(l:/100.127.97.210:39894 <-> r:server-proxy.xxx.net/155.180.102.45:11443,closed=false)=>HttpChannelOverHTTP@6c77a6c2(exchange=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]})[send=HttpSenderOverHTTP@1dcc6c7b(req=QUEUED,failure=null)[HttpGenerator@5bac2c8f{s=START}],recv=HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}]]] in HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}] 2024-04-10T14:25:22.936Z DEBUG 1 --- [ent@3c5044fa-41] o.e.j.c.t.internal.HttpReceiverOverHTTP : Parsing DirectByteBuffer@5f3a6a2f[p=0,l=831,c=16384,r=831]={<<<HTTP/1.1 407 Proxy Authen... >>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00} in HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[null 0 null]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=START,0 of -1}] 2024-04-10T14:25:22.936Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : parseNext s=START DirectByteBuffer@5f3a6a2f[p=0,l=831,c=16384,r=831]={<<<HTTP/1.1 407 Proxy Authen... >>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00} 2024-04-10T14:25:22.936Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : START --> SPACE1(HTTP/1.1) 2024-04-10T14:25:22.937Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : SPACE1 --> STATUS 2024-04-10T14:25:22.937Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : STATUS --> SPACE2(407) 2024-04-10T14:25:22.937Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : SPACE2 --> REASON 2024-04-10T14:25:22.937Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : REASON --> HEADER 2024-04-10T14:25:22.937Z DEBUG 1 --- [ent@3c5044fa-41] o.e.jetty.client.transport.HttpReceiver : Invoking responseBegin for HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[HTTP/1.1 407 Proxy Authentication Required]@44d1c363[PENDING/null]} on HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[HTTP/1.1 407 Proxy Authentication Required]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=HEADER,0 of -1}] 2024-04-10T14:25:22.938Z DEBUG 1 --- [ent@3c5044fa-41] o.e.jetty.client.transport.HttpReceiver : Executing responseBegin for HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[HTTP/1.1 407 Proxy Authentication Required]@44d1c363[PENDING/null]} on HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[HTTP/1.1 407 Proxy Authentication Required]@44d1c363[PENDING/null]},rsp=IDLE,failure=null)[HttpParser{s=HEADER,0 of -1}] 2024-04-10T14:25:22.940Z DEBUG 1 --- [ent@3c5044fa-41] o.e.jetty.client.transport.HttpReceiver : Response HttpResponse[HTTP/1.1 407 Proxy Authentication Required]@44d1c363 found protocol handler org.eclipse.jetty.client.ProxyAuthenticationProtocolHandler@597a30a9 2024-04-10T14:25:22.940Z DEBUG 1 --- [ent@3c5044fa-41] o.e.j.client.transport.HttpConversation : Exchanges in conversation 1, override=org.eclipse.jetty.client.AuthenticationProtocolHandler$AuthenticationListener@32c3c66a, listeners=org.eclipse.jetty.client.transport.ResponseListeners@2ac1e509 2024-04-10T14:25:22.940Z DEBUG 1 --- [ent@3c5044fa-41] o.e.jetty.client.transport.HttpReceiver : Response begin HttpResponse[HTTP/1.1 407 Proxy Authentication Required]@44d1c363 2024-04-10T14:25:22.940Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : HEADER:FIELD --> IN_VALUE 2024-04-10T14:25:22.940Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : HEADER:IN_VALUE --> FIELD(Proxy-Authenticate: NEGOTIATE) 2024-04-10T14:25:22.940Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : parsedHeader(null) header=Proxy-Authenticate, headerString=[Proxy-Authenticate], valueString=[NEGOTIATE] 2024-04-10T14:25:22.940Z DEBUG 1 --- [ent@3c5044fa-41] o.e.jetty.client.transport.HttpReceiver : Invoking responseHeader for Proxy-Authenticate: NEGOTIATE on HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[HTTP/1.1 407 Proxy Authentication Required]@44d1c363[PENDING/null]},rsp=BEGIN,failure=null)[HttpParser{s=HEADER,0 of -1}] 2024-04-10T14:25:22.941Z DEBUG 1 --- [ent@3c5044fa-41] o.e.jetty.client.transport.HttpReceiver : Executing responseHeader on HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[HTTP/1.1 407 Proxy Authentication Required]@44d1c363[PENDING/null]},rsp=BEGIN,failure=null)[HttpParser{s=HEADER,0 of -1}] 2024-04-10T14:25:22.941Z DEBUG 1 --- [ent@3c5044fa-41] o.e.jetty.client.transport.HttpReceiver : Notifying header Proxy-Authenticate: NEGOTIATE 2024-04-10T14:25:22.941Z DEBUG 1 --- [ent@3c5044fa-41] o.e.jetty.client.transport.HttpReceiver : Header Proxy-Authenticate: NEGOTIATE notified, processing needed

2024-04-10T14:25:22.941Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : HEADER:FIELD --> IN_VALUE 2024-04-10T14:25:22.941Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : HEADER:IN_VALUE --> FIELD(Proxy-Authenticate: NTLM) 2024-04-10T14:25:22.941Z DEBUG 1 --- [ent@3c5044fa-41] org.eclipse.jetty.http.HttpParser : parsedHeader(null) header=Proxy-Authenticate, headerString=[Proxy-Authenticate], valueString=[NTLM] 2024-04-10T14:25:22.941Z DEBUG 1 --- [ent@3c5044fa-41] o.e.jetty.client.transport.HttpReceiver : Invoking responseHeader for Proxy-Authenticate: NTLM on HttpReceiverOverHTTP@112c2642(ex=HttpExchange@1b8ba5a8{req=TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@3b908fca[TERMINATED/null] res=HttpResponse[HTTP/1.1 407 Proxy Authentication Required]@44d1c363[PENDING/null]},rsp=HEADER,failure=null)[HttpParser{s=HEADER,0 of -1}]

How to reproduce?

richardydhan commented 5 months ago

below trace may help:

org.eclipse.jetty.client.HttpResponseException: Unexpected HttpContentResponse[HTTP/1.1 407 Proxy Authentication Required - 513 bytes] for TunnelRequest[CONNECT xxx.sandbox.my.salesforce.com:443 HTTP/1.1]@682d6ba7 at org.eclipse.jetty.client.HttpProxy$CreateTunnelPromise$TunnelListener.onHeaders(HttpProxy.java:251) at org.eclipse.jetty.client.transport.ResponseListeners.notifyHeaders(ResponseListeners.java:162) at org.eclipse.jetty.client.transport.ResponseListeners.lambda$addHeadersListener$2(ResponseListeners.java:147) at org.eclipse.jetty.client.transport.ResponseListeners.notifyHeaders(ResponseListeners.java:162) at org.eclipse.jetty.client.transport.ResponseListeners.emitEvents(ResponseListeners.java:391) at org.eclipse.jetty.client.transport.ResponseListeners.emitSuccess(ResponseListeners.java:405) at org.eclipse.jetty.client.transport.ResponseListeners.emitSuccessComplete(ResponseListeners.java:417) at org.eclipse.jetty.client.AuthenticationProtocolHandler$AuthenticationListener.forwardSuccessComplete(AuthenticationProtocolHandler.java:269) at org.eclipse.jetty.client.AuthenticationProtocolHandler$AuthenticationListener.onComplete(AuthenticationProtocolHandler.java:145) at org.eclipse.jetty.client.transport.ResponseListeners.notifyComplete(ResponseListeners.java:349) at org.eclipse.jetty.client.transport.ResponseListeners.lambda$addCompleteListener$7(ResponseListeners.java:334) at org.eclipse.jetty.client.transport.ResponseListeners.notifyComplete(ResponseListeners.java:349) at org.eclipse.jetty.client.transport.ResponseListeners.notifyComplete(ResponseListeners.java:341) at org.eclipse.jetty.client.transport.HttpReceiver.terminateResponse(HttpReceiver.java:417) at org.eclipse.jetty.client.transport.HttpReceiver.terminateResponse(HttpReceiver.java:399) at org.eclipse.jetty.client.transport.HttpReceiver.lambda$responseSuccess$3(HttpReceiver.java:364) at org.eclipse.jetty.util.thread.SerializedInvoker$Link.run(SerializedInvoker.java:191) at org.eclipse.jetty.util.thread.SerializedInvoker.run(SerializedInvoker.java:117) at org.eclipse.jetty.client.transport.HttpReceiver.responseHeaders(HttpReceiver.java:240) at org.eclipse.jetty.client.transport.internal.HttpReceiverOverHTTP.lambda$headerComplete$2(HttpReceiverOverHTTP.java:435) at org.eclipse.jetty.client.transport.internal.HttpReceiverOverHTTP.parse(HttpReceiverOverHTTP.java:320) at org.eclipse.jetty.client.transport.internal.HttpReceiverOverHTTP.parseAndFill(HttpReceiverOverHTTP.java:250) at org.eclipse.jetty.client.transport.internal.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:76) at org.eclipse.jetty.client.transport.internal.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:90) at org.eclipse.jetty.client.transport.internal.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:194) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100) at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:478) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:441) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:293) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.produce(AdaptiveExecutionStrategy.java:195) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:979) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1209) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1164) at java.base/java.lang.Thread.run(Thread.java:842)