Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

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

Open
richardydhan opened this issue Apr 10, 2024 · 1 comment
Labels
Bug For general bugs on Jetty side

Comments

@richardydhan
Copy link

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 richardydhan added the Bug For general bugs on Jetty side label Apr 10, 2024
@richardydhan
Copy link
Author

richardydhan commented Apr 10, 2024

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)

@richardydhan richardydhan changed the title SPNEGOAuthentication does not work for proxy authentication authorization in Cometd SPNEGOAuthentication does not work for proxy authentication authorization in CometD Apr 10, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug For general bugs on Jetty side
Projects
None yet
Development

No branches or pull requests

1 participant