dCache / dcache

dCache - a system for storing and retrieving huge amounts of data, distributed among a large number of heterogenous server nodes, under a single virtual filesystem tree with a variety of standard access methods
https://dcache.org
290 stars 136 forks source link

WebDAV returns 401 and empty page to Chrome/Firefox with latest snapshot #5880

Closed onnozweers closed 3 years ago

onnozweers commented 3 years ago

Dear dCache devs,

I'm testing the latest snapshot on our test server and it seems all my WebDAV doors are broken in Chrome and Firefox on MacOS and in Firefox on Ubuntu. The doors don't ask for credentials but instead return an empty page with a 401 status in the header. Strangely enough, the TPC smoke test does not seem to have any problem with the doors; neither does Cyberduck. The dCacheView interface still works.

The config of one door:

[webdav443-${host.name}Domain]
[webdav443-${host.name}Domain/webdav]
webdav.cell.name=webdav443-${host.name}
webdav.redirect.on-read=true
webdav.redirect.on-write=true
webdav.authn.protocol=https
webdav.net.port=443
# Authentication: username/password & macaroons, but no X509
webdav.authn.basic=true
webdav.authn.accept-client-cert = false

From the .access log:

level=WARN ts=2021-04-30T11:43:56.236+0200 event=org.dcache.webdav.request request.method=GET request.url=https://dolphin12.grid.surfsara.nl/ response.code=401 response.reason="login failed" socket.remote=[2001:610:108:203d:a000::1a7]:64008 user-agent="Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:88.0) Gecko/20100101 Firefox/88.0" duration=0

Here is some logging from the door with level debug, while opening the page in a browser.

30 Apr 2021 11:43:56 (webdav443-dolphin12) [] CONTENT_LENGTH
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] generate: FLUSH for org.eclipse.jetty.server.HttpConnection$SendCallback@494b54f2[PROCESSING][i=HTTP/1.1{s=401,h=4,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@2b82564b] ([p=0,l=188,c=8192,r=188],[p=0,l=0,c=0,r=0],true)@COMPLETING
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] >flush SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=8/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=W,to=15/300000}=>HttpConnection@37bd224a[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6d46ebfb{s=COMPLETING}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=https://dolphin12.grid.surfsara.nl/,age=4}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] flush b[0]=HeapByteBuffer@4e7fe7d6[p=0,l=188,c=8192,r=188]={<<<HTTP/1.1 401 login failed...\r\nContent-Length: 0\r\n\r\n>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] flush NOT_HANDSHAKING
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] wrap Status = OK HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 188 bytesProduced = 226 sequenceNumber = 0 [p=0,l=226,c=17408,r=226] ioDone=false/false
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] flushed 226 SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=9/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/0,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=W,to=15/300000}=>HttpConnection@37bd224a[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6d46ebfb{s=COMPLETING}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=https://dolphin12.grid.surfsara.nl/,age=5}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] net flushed=true, ac=true
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] <flush true SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=0/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=W,to=15/300000}=>HttpConnection@37bd224a[p=HttpParser{s=END,0 of -1},g=HttpGenerator@6d46ebfb{s=COMPLETING}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=https://dolphin12.grid.surfsara.nl/,age=5}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] Flushed=true written=188 remaining=0 WriteFlusher@43dbad48{WRITING}->null
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] generate: DONE for org.eclipse.jetty.server.HttpConnection$SendCallback@494b54f2[PROCESSING][i=HTTP/1.1{s=401,h=4,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@2b82564b] ([p=188,l=188,c=8192,r=0],[p=0,l=0,c=0,r=0],true)@END
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] onWriteComplete(true,null) s=CLOSING,api=BLOCKED,sc=false,e=null->s=CLOSED,api=BLOCKING,sc=false,e=null c=null cb=org.eclipse.jetty.util.Callback$3@94c2fbc w=false
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] completed HttpChannelState@3e6795d{s=HANDLING rs=COMPLETING os=COMPLETED is=IDLE awp=false se=false i=false al=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] unhandle HttpChannelState@3e6795d{s=HANDLING rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] nextAction(false) TERMINATED HttpChannelState@3e6795d{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] action TERMINATED HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=https://dolphin12.grid.surfsara.nl/,age=5}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] onCompleted for / written=0
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] recycle HttpChannelState@3e6795d{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] reset HttpParser{s=END,0 of -1}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] END --> START
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] !handle TERMINATED HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] >fill SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=0/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=16/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] fill NOT_HANDSHAKING
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] filled 0 HeapByteBuffer@df58b00[p=0,l=0,c=17408,r=0]={<<<>>>\x14\x03\x03\x00\x01\x01\x17\x03\x03...\x00\x00\x00\x00\x00\x00\x00}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] net filled=0
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] unwrap net_filled=0 Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 0 bytesProduced = 0 encryptedBuffer=[p=0,l=0,c=17408,r=0] unwrapBuffer=HeapByteBuffer@5ad6eaf2[p=0,l=0,c=17408,r=0]={<<<>>>\x17\x03\x03\x00\xDd\x17+\x19\xAc...\x00\x00\x00\x00\x00\x00\x00} appBuffer=HeapByteBuffer@5ad6eaf2[p=0,l=0,c=17408,r=0]={<<<>>>\x17\x03\x03\x00\xDd\x17+\x19\xAc...\x00\x00\x00\x00\x00\x00\x00}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] <fill f=0 uf=true SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=1/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=17/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] >fill SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=1/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=17/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] fill NOT_HANDSHAKING
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] filled 0 HeapByteBuffer@df58b00[p=0,l=0,c=17408,r=0]={<<<>>>\x14\x03\x03\x00\x01\x01\x17\x03\x03...\x00\x00\x00\x00\x00\x00\x00}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] net filled=0
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] unwrap net_filled=0 Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 0 bytesProduced = 0 encryptedBuffer=[p=0,l=0,c=17408,r=0] unwrapBuffer=HeapByteBuffer@5ad6eaf2[p=0,l=0,c=17408,r=0]={<<<>>>\x17\x03\x03\x00\xDd\x17+\x19\xAc...\x00\x00\x00\x00\x00\x00\x00} appBuffer=HeapByteBuffer@5ad6eaf2[p=0,l=0,c=17408,r=0]={<<<>>>\x17\x03\x03\x00\xDd\x17+\x19\xAc...\x00\x00\x00\x00\x00\x00\x00}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] <fill f=0 uf=true SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=1/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=17/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] HttpConnection@37bd224a::DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=17/300000} filled 0 HeapByteBuffer@5ad6eaf2[p=0,l=0,c=17408,r=0]={<<<>>>\x17\x03\x03\x00\xDd\x17+\x19\xAc...\x00\x00\x00\x00\x00\x00\x00}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] HttpConnection@37bd224a::DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=17/300000} parse HeapByteBuffer@5ad6eaf2[p=0,l=0,c=17408,r=0]={<<<>>>\x17\x03\x03\x00\xDd\x17+\x19\xAc...\x00\x00\x00\x00\x00\x00\x00} {}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] parseNext s=START HeapByteBuffer@5ad6eaf2[p=0,l=0,c=17408,r=0]={<<<>>>\x17\x03\x03\x00\xDd\x17+\x19\xAc...\x00\x00\x00\x00\x00\x00\x00}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] HttpConnection@37bd224a::DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=17/300000} parsed false HttpParser{s=START,0 of -1}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] releaseRequestBuffer HttpConnection@37bd224a::DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=17/300000}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] fillInterested HttpConnection@37bd224a::DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=17/300000}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] interested FillInterest@33373b6b{AC.ReadCB@37bd224a{HttpConnection@37bd224a::DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}}}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] >needFillInterest s=IDLE/IDLE uf=true ei=null di=null SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=2/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] <needFillInterest s=IDLE/INTERESTED f=false i=true w=null
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] ensureFillInterested SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=-,flush=-,to=2/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] interested FillInterest@69759e43{SSLC.NBReadCB@569b32e9{SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}{io=0/0,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}}}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] changeInterests p=false 0->1 for SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}{io=0/1,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] Queued change lazy=false org.eclipse.jetty.io.ChannelEndPoint$$Lambda$309/0x0000000840606840@6676f5fe on ManagedSelector@24648f7f{STARTED} id=3 keys=1 selected=0 updates=0
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] Wakeup on submit ManagedSelector@24648f7f{STARTED} id=3 keys=1 selected=0 updates=1
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] HttpConnection@37bd224a::DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000} onFillable exit HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] Selector sun.nio.ch.EPollSelectorImpl@13020142 woken with none selected
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] Selector sun.nio.ch.EPollSelectorImpl@13020142 woken up from select, 0/0/1 selected
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] Selector sun.nio.ch.EPollSelectorImpl@13020142 processing 0 keys, 1 updates
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] updateable 1
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] <c.onFillable SslConnection@569b32e9::SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}{io=0/1,kio=0,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] update org.eclipse.jetty.io.ChannelEndPoint$$Lambda$309/0x0000000840606840@6676f5fe
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] ReservedThreadExecutor@2454de3c{s=2/48,p=0}@586698d0 waiting
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] Key interests updated 0 -> 1 on SocketChannelEndPoint@79e5a356{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=0/300000}{io=1/1,kio=1,kro=1}->SslConnection@569b32e9{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@574d8564{l=/2001:610:108:203a:0:0:1:46:443,r=/2001:610:108:203d:a000:0:0:1a7:64008,OPEN,fill=FI,flush=-,to=1/300000}=>HttpConnection@37bd224a[p=HttpParser{s=START,0 of -1},g=HttpGenerator@6d46ebfb{s=START}]=>HttpChannelOverHttp@e8bec14{s=HttpChannelState@3e6795d{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] updates 0
30 Apr 2021 11:43:56 (webdav443-dolphin12) [] Selector sun.nio.ch.EPollSelectorImpl@13020142 waiting with 1 keys
30 Apr 2021 11:43:57 (webdav443-dolphin12) [NIC auto-discovery] Scan took 6.527 ms
onnozweers commented 3 years ago

Possibly related to #5894

paulmillar commented 3 years ago

Hi Onno,

Sorry for the delay in chasing this up. I've not been able to reproduce this problem locally.

Unfortunately the logging you provided doesn't show anything interesting. The access log file simply says the door replied with 401 and the debug logging only seems to capture Jetty replying with the 401 response, but not the code that generated this response.

The 401 response is meant to indicate a login failure. This suggests that either gPlazma returns a login failure or the door experienced a login failure in the past and has cached that response. In either, gPlazma should have seen a login failure in the (recent) past. The first time gPlazma sees a login failure (with a specific set of credentials) it logs the result.

Therefore, I suggest looking for a login failure being logged by gPlazma.

You can force gPlazma to provide a detailed log the next login failure by updating the gplazma.conf file (e.g,. touch /etc/dcache/gplazma.conf).

You can also ask the door to list all cached login results with the login dump cache admin command. You can also clear the cache with the login clear cache admin command. Cached results are not kept indefinitely, but cleared automatically after a while.

I suggest checking the webdav door's login cache, then try manually clearing the WebDAV door's cache, touching gplazma.conf and (trying to) reproduce the problem. If there's another login failure then check the gPlazma log file to see if anything is reported.

paulmillar commented 3 years ago

One other thing -- could you post your configuration for the WebDAV door where you see this problem?

It could be a configuration-specific problem.

onnozweers commented 3 years ago

Hi Paul,

I did this:

[root@dolphin12 /var/log]# touch /etc/dcache/gplazma.conf
[root@dolphin12 /var/log]# dcache-admin-command webdav443-dolphin12 'login clear cache'

Then I opened a private browser window and accessed the webdav443-dolphin12 door. This appeared in the gPlazma log:

17 May 2021 10:13:20 (gPlazma) [webdav443-dolphin12 Login] LDAP conection is not secure!
17 May 2021 10:13:20 (gPlazma) [webdav443-dolphin12 Login] LDAP conection is not secure!
17 May 2021 10:13:20 (gPlazma) [webdav443-dolphin12 Login] LDAP conection is not secure!
17 May 2021 10:13:21 (gPlazma) [webdav443-dolphin12 Login] Login attempt failed; detailed explanation follows:
LOGIN FAIL
 |    in: Origin[2001:610:108:203d:e000::281]
 |   out: Origin[2001:610:108:203d:e000::281]
 |
 +--AUTH OK
 |   |
 |   +--x509 OPTIONAL:FAIL (no X.509 certificate chain) => OK
 |   |
 |   +--voms OPTIONAL:FAIL (no X509 certificate chain) => OK
 |   |
 |   +--kpwd OPTIONAL:FAIL (no username and password) => OK
 |   |
 |   +--jaas OPTIONAL:FAIL (no login name) => OK
 |   |
 |   +--ldap OPTIONAL:FAIL (no login name) => OK
 |   |
 |   +--scitoken OPTIONAL:FAIL (no JWT bearer token) => OK
 |   |
 |   +--oidc OPTIONAL:FAIL (No bearer token in the credentials) => OK
 |
 +--MAP OK
 |   |
 |   +--gridmap OPTIONAL:FAIL (no mapping) => OK
 |   |
 |   +--vorolemap OPTIONAL:FAIL (no record) => OK
 |   |
 |   +--mutator OPTIONAL:OK => OK
 |   |
 |   +--multimap OPTIONAL:FAIL (no mappable principals) => OK
 |   |
 |   +--multimap OPTIONAL:FAIL (no mappable principals) => OK
 |   |
 |   +--multimap SUFFICIENT:FAIL (no mappable principals) => OK
 |   |
 |   +--multimap SUFFICIENT:FAIL (no mappable principals) => OK
 |   |
 |   +--authzdb SUFFICIENT:FAIL (no mappable principal) => OK
 |   |
 |   +--kpwd SUFFICIENT:FAIL (no mappable principals) => OK
 |   |
 |   +--ldap SUFFICIENT:FAIL (no username) => OK
 |
 +--ACCOUNT OK
 |   |
 |   +--banfile REQUISITE:OK => OK
 |   |
 |   +--kpwd SUFFICIENT:OK => OK (ends the phase)
 |
 +--SESSION OK
 |   |
 |   +--roles REQUIRED:OK => OK
 |   |
 |   +--authzdb SUFFICIENT:FAIL (no username principal) => OK
 |   |
 |   +--kpwd SUFFICIENT:FAIL (no record found) => OK
 |   |
 |   +--ldap SUFFICIENT:OK => OK (ends the phase)
 |
 +--VALIDATION FAIL (no username, no UID, no primary GID)

Could the "LDAP conection is not secure" be the cause of the problem? I would expect an "internal server error" in that case.

The login cache:

[root@dolphin12 /var/log]# dcache-admin-command webdav443-dolphin12 'login dump cache'
Max Cache size: 1024
Max Cache time: 10 minutes
Login:
   {origin:2001:610:108:203d:e000::281} => CacheException(rc=10018;msg=login failed)
Map:
ReverseMap:
onnozweers commented 3 years ago

The piece of code was easy to find, thanks to the spelling error 😄

        boolean isSSL = ldapUrl.startsWith("ldaps");
        if (!isSSL) {
            LOGGER.warn("LDAP conection is not secure!");
        }

Is perhaps our LDAP config outdated? It hasn't changed in years.

[root@dolphin12 /etc/dcache]# cat jgss.conf
LdapGplazma {
com.sun.security.auth.module.LdapLoginModule REQUIRED
userProvider="ldaps://**********************:636/ou=Users,dc=hpcv,dc=sara,dc=nl"
userFilter="(uid={USERNAME})"
useSSL=true;
};
paulmillar commented 3 years ago

The error LDAP conection is not secure! is just a warning, it doesn't stop anything from working.

Note that the error message comes from the ldap plugin and the configuration you posted (jgss.conf) is for the jaas plugin. You should check your gplazma.ldap.url configuration property: that (likely) has ldap:// (insecure) rather than ldaps:// (secure).

paulmillar commented 3 years ago

Could you copy (into this ticket) the configuration for your WebDAV door?

I'll try to reproduce the problem based on that information.

onnozweers commented 3 years ago

The gplazma.ldap.url is not set, except for a commented line that I experimented with long time ago.

[root@dolphin12 /etc/dcache]# grep gplazma.ldap.url * layouts/dolphin12.conf 
grep: admin: Is a directory
grep: layouts: Is a directory
grep: webdav-static-content: Is a directory
layouts/dolphin12.conf:#gplazma.ldap.url = ldaps://*******************:636/

The WebDAV config:

[webdav443-${host.name}Domain]
dcache.java.memory.heap=8g
[webdav443-${host.name}Domain/webdav]
webdav.cell.name=webdav443-${host.name}
webdav.redirect.on-read=true
webdav.redirect.on-write=true
webdav.authn.protocol=https
webdav.net.port=443
# Authentication: username/password & macaroons, but no X509
webdav.authn.basic=true
webdav.authn.accept-client-cert = false
# Allow dCache View to use this door
webdav.allowed.client.origins = https://dolphin12.grid.surfsara.nl:20443

Other doors have the same issue. I have a door with X509 auth. It asks the browser for a client cert as expected, but then returns a blank page too.

[webdav2884-${host.name}Domain]
dcache.java.memory.heap=8g
dcache.java.options.extra = \
    -Djava.security.properties=/etc/dcache/maximum.java.security \
    -Djdk.tls.ephemeralDHKeySize=2048
[webdav2884-${host.name}Domain/webdav]
webdav.cell.name = webdav2884-${host.name}
webdav.authn.protocol = https
webdav.net.port = 2884
# Disable redirects because they send client to HTTP, not HTTPS!
webdav.redirect.on-read = false
webdav.redirect.on-write = false
# Do not support username/password auth
webdav.authn.basic = false
# Support X509 authentication
webdav.authn.accept-client-cert = true
# WebDAV security enhancements
webdav.custom-response-header!Content-Security-Policy = \
    default-src 'none' ; \
    img-src 'self' data: ; \
    style-src 'self' 'unsafe-inline' ; \
    script-src 'self'; font-src 'self'
webdav.custom-response-header!X-Frame-Options = SAMEORIGIN
webdav.custom-response-header!X-XSS-Protection = 1; mode=block
webdav.custom-response-header!X-Content-Type-Options = nosniff
webdav.custom-response-header!Referrer-Policy = strict-origin-when-cross-origin
webdav.custom-response-header!Access-Control-Allow-Origin = https://dolphin12.grid.surfsara.nl:20443

Global WebDAV settings:

[root@dolphin12 /etc/dcache]# grep ^webdav dcache.conf 
webdav.templates.config!head_title = SURFsara dCache ${dcache.version} TEST
webdav.templates.config!header_brand = <img src="${webdav.static-content.uri}/surfsara-logo.png" height="26" width="70">
webdav.templates.config!header_text = ${webdav.templates.config!head_title}
webdav.templates.config!footer = Powered by <a href="https://dcache.org/">dCache</a> | <a href="http://doc.grid.surfsara.nl/en/latest/Pages/Advanced/grid_storage.html">Documentation</a> | <a href="https://dolphin12.grid.surfsara.nl:20443/">dCache Frontend</a>
webdav.static-content.dir.local = /etc/dcache/webdav-static-content
webdav.authn.hostcert.cert=/etc/grid-security/chain.pem
webdav.redirect.allow-https=true
onnozweers commented 3 years ago

Hi Paul, do you need any more information?

Cheers, Onno

paulmillar commented 3 years ago

Hi Onno,

Sorry for the delay in replying.

I've (again) tried to reproduce the problem, but unfortunately dCache is working for me: I am prompted for a username+password when I try to view a private directory.

The login failure you see is actually expected: at least when using a browser. When it doesn't have a stored credential, it tries accessing resources without any credential. If the resource requires authentication then dCache should reply 401 and include a hint to the client (the WWW-Authenticate header), describing how to authenticate. The web-browser should then prompt the user for a username+password and use that when making another request for the same resource. The browser then caches the credential.

I don't know CyberDuck very well, but my guess is that it doesn't bother attempting to access resources without a password: it simply makes requests using the username+password (assuming a particular encoding). Should should be able to tell if this is the case: do you see a failed login attempt from CyberDuck? You may need to reset gplazma (touch /etc/dcache/gplazma.conf) to see it.

For HTTP-TPC, the authentication is done first with X.509 to obtain a macaroon and then using that macaroon to do the data transfer. In either case, the client doesn't try to access a resource anonymously. So, it's a different behaviour and (quite reasonable) that it works.

For dCacheView, we have a different problem. We actually want to prevent the browser from showing any kind of prompt, but allow the JavaScript code to handle authentication. This is current rather clunky and the only way to do it is for dCache to suppress the WWW-Authenticate header when the client is a browser running dCacheView. This is an ugly hack, but something that should only apply to dCacheView and not for general browser interactions.

So, my suggestions for going forward:

  1. Please check whether that includes the WWW-Authenticate header in the 401 response? Both Firefox and Chrome provide a built-in tool called something like "developer view" or "developer's toolbox". This should allow you to inspect the HTTP requests going over the network. You should see the GET request that's triggering the failed login along with the response from dCache.
  2. Could you double-check with the latest version of dCache? I don't think anything has changed that would affect this, but it would be good to double-check.
  3. Could you try restarting your web-browser and try viewing dCache through a "privacy mode" window. (You might have already done this -- it wasn't 100% clear to me from your description).
  4. Finally (as a shot-in-the-dark) would it be possible to try disabling/removing the webdav.custom-response-header just to see if that has any effect?

Cheers, Paul.

nsc-jens commented 3 years ago

Related: [www.dcache.org #10159] Browser access to WebDAV in dCache 7.1

nsc-jens commented 3 years ago

Works (7.0, dcachetest1.swestore.se): https://webdav-test.swestore.se/snic/ Does not work (7.1, delenn.swestore.se): https://webdav.swestore.se/snic/ Works with workaround* (7.1, delenn.swestore.se, fooDomain): https://webdav.swestore.se:22443/snic/

* webdav.custom-response-header!WWW-Authenticate=Basic realm="Swestore", charset="UTF-8"

paulmillar commented 3 years ago

Thanks for the info @nsc-jens ,

If you trigger (what should be) a login prompt, do you see the Suppress-WWW-Authenticate header in the server's response?

onnozweers commented 3 years ago

I built today's snapshot, configured Jens's workaround and opened a private browser window. I got a sign in prompt. Before submitting, the get request in the console shows no headers at all (not sure if this is meant to be). After submitting my name/password, these are the reported headers in the browser console:

GET https://dolphin12.grid.surfsara.nl:2880/users/onno/ [HTTP/1.1 200 OK 51173ms]

GET https://dolphin12.grid.surfsara.nl:2880/users/onno/ Status200 OK Version HTTP/1.1 Transferred 8.07 KB (7.71 KB size)

HTTP/1.1 200 OK
Date: Wed, 25 Aug 2021 08:09:19 GMT
WWW-Authenticate: Basic realm="Surfsara-test", charset="UTF-8"
Server: dCache/7.2.0-SNAPSHOT
Accept-Ranges: bytes
ETag: "00007560C30AD2A141068B6B1AB986C13B77_-2020876407"
Last-Modified: Wed, 31 Mar 2021 09:09:54 GMT
Content-Type: text/html;charset=utf-8
Cache-Control: no-cache
Transfer-Encoding: chunked

GET /users/onno/ HTTP/1.1
Host: dolphin12.grid.surfsara.nl:2880
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:91.0) Gecko/20100101 Firefox/91.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Accept-Language: en-US,en;q=0.7,nl;q=0.3
Accept-Encoding: gzip, deflate, br
DNT: 1
Connection: keep-alive
Upgrade-Insecure-Requests: 1
Sec-Fetch-Dest: document
Sec-Fetch-Mode: navigate
Sec-Fetch-Site: none
Sec-Fetch-User: ?1
Authorization: Basic **************************
onnozweers commented 3 years ago

Without Jens's workaround, these are the headers:

GET https://dolphin12.grid.surfsara.nl:2880/users/onno/ [HTTP/1.1 401 login failed 3746ms]

GET https://dolphin12.grid.surfsara.nl:2880/users/onno/ Status 401 login failed Version HTTP/1.1 Transferred 116 B (0 B size)

HTTP/1.1 401 login failed
Date: Wed, 25 Aug 2021 08:17:53 GMT
Server: dCache/7.2.0-SNAPSHOT
Content-Length: 0

GET /users/onno/ HTTP/1.1
Host: dolphin12.grid.surfsara.nl:2880
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:91.0) Gecko/20100101 Firefox/91.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Accept-Language: en-US,en;q=0.7,nl;q=0.3
Accept-Encoding: gzip, deflate, br
DNT: 1
Connection: keep-alive
Upgrade-Insecure-Requests: 1
Sec-Fetch-Dest: document
Sec-Fetch-Mode: navigate
Sec-Fetch-Site: none
Sec-Fetch-User: ?1
paulmillar commented 3 years ago

Thanks for the info.

Could you check whether you see a line in the WebDAV door's pinboard that starts Login failed for?

onnozweers commented 3 years ago

I disabled Jens's workaround, restarted the door, and tried again to access the door in Firefox. These lines were added to the pinboard:

25 Aug 2021 14:10:04 [jetty-47] [] Login failed for GET on /users/onno/: login failed
25 Aug 2021 14:10:04 [jetty-77] [] Login failed for GET on /favicon.ico: login failed
paulmillar commented 3 years ago

OK, thanks -- I think I understand the problem. I just need to figure out why I can't reproduce it!

paulmillar commented 3 years ago

Patch: https://rb.dcache.org/r/13145/

paulmillar commented 3 years ago

Hi Onno,

Just to report back: the problem is (I believe) now understood. There's a fix that has passed code-review and should be part of the next release cycle.

Cheers, Paul.

onnozweers commented 3 years ago

Hi Paul,

Thanks! I've built the latest snapshot including 4a1ffa1 and it seems to work as expected.

Cheers, Onno

kofemann commented 3 years ago

Hi Onno,

thanks for quick testing.