(some) token authenticated ATLAS transfers start to fail when switching over to multimap #7995
Description
Hey.
This is with dcache 10.2.18 and I’ve had already reported it earlier in the RT ticket 10739, but that hasn’t really solved it and to me it anyway seems more like a bug, thus reporting it here again.
Backstory:
So far I’ve been using the following gplazma.conf:
auth optional x509
auth optional voms
auth optional oidc
map optional vorolemap
map sufficient authzdb
map optional gridmap
map requisite authzdb
session requisite authzdb
which is pretty standard, except perhaps for the double authzdb around gridmap, which is merely done to finish any cert + no VOMS which matches an entry in gridmap with that, so that I can do different maping for the same DN with a cert-only-access and with a cert+VOMS-access.
dcache.conf has these:
gplazma.oidc.provider!atlas=https://atlas-auth.web.cern.ch/ -profile=wlcg -prefix=/pnfs/lrz-muenchen.de/data/atlas/dq2 -authz-id="uid:11001 gid:11000 username:atlas-production"
gplazma.oidc.provider!atlas_new=https://atlas-auth.cern.ch/ -profile=wlcg -prefix=/pnfs/lrz-muenchen.de/data/atlas/dq2 -authz-id="uid:11001 gid:11000 username:atlas-production"
gplazma.oidc.audience-targets=https://wlcg.cern.ch/jwt/v1/any https://lcg-lrz-http.grid.lrz.de roots://lcg-lrz-rootd.grid.lrz.de:1094 lcg-lrz-http.grid.lrz.de lcg-lrz-rootd.grid.lrz.de
vorolemap has:
"*" "/ops" ops
"*" "/ops/Role=lcgadmin" ops
"*" "/ops/NGI/Germany" ops
"*" "/dteam" dteam
"*" "/atlas" atlas
"*" "/atlas/Role=pilot" atlas
"*" "/atlas/Role=production" atlas-production
"*" "/atlas/de" atlas
"*" "/atlas/de/Role=production" atlas-production
"*" "/atlas/perf-muons" atlas
"*" "/atlas/perf-muons/Role=production" atlas
"*" "/belle" belle
and authzdb has:
version 2.1
authorize calestyo read-write 10100 10100 / / /
authorize ops read-write 12000 12000 / / /
authorize dteam read-write 13000 13000 / / /
authorize atlas read-write 11000 11000 / / /
authorize atlas-production read-write 11001 11000 / / /
authorize belle read-write 14000 14000 / / /
That setup works.
Now we want to support PUNCH4NFDI, which uses tokens for authn/z but **not** WLCG profile.
For this, AFAIU, multimap must be used. Also that is anyway considered to be the “future”, so I decided to migrate away from gridmap, vorolemap and authzdb to multimap + omnisession.
New setup would look like this.
gplazma.conf:
auth optional x509
auth optional voms
auth optional oidc
map sufficient multimap
map sufficient multimap gplazma.multimap.file=/etc/dcache/access-control/multimap-dn-without-fqan
session requisite omnisession
multimap (the regular one for the first map above:
fqan:/ops,true username:ops uid:12000 gid:12000,true
fqan:/ops/Role=lcgadmin,true username:ops uid:12000 gid:12000,true
fqan:/ops/NGI/Germany,true username:ops uid:12000 gid:12000,true
fqan:/dteam,true username:dteam uid:13000 gid:13000,true
fqan:/atlas,true username:atlas uid:11000 gid:11000,true
fqan:/atlas/Role=pilot,true username:atlas uid:11000 gid:11000,true
fqan:/atlas/Role=production,true username:atlas-production uid:11001 gid:11000,true
fqan:/atlas/de,true username:atlas uid:11000 gid:11000,true
fqan:/atlas/de/Role=production,true username:atlas-production uid:11001 gid:11000,true
fqan:/atlas/perf-muons,true username:atlas uid:11000 gid:11000,true
fqan:/atlas/perf-muons/Role=production,true username:atlas uid:11000 gid:11000,true
fqan:/belle,true username:belle uid:14000 gid:14000,true
fqan:/belle/Role=production,true username:belle uid:14000 gid:14000,true
multimap-dn-without-fqan, which replaces my previous gridmap file e.g. like:
dn:"/C=DE/O=GridGermany/OU=Ludwig-Maximilians-Universitaet Muenchen/OU=Faculty of Physics/CN=Christoph Anton Mitterer" username:calestyo uid:10100 gid:10100,true
omnisession:
DEFAULT root:/ home:/ prefix:/
So far, no PUNCH4NFDI integration yet.
When I enable that configuration, I get quite massive transfer errors, which are rejection with permissions problems. As far as I can tell, it doesn’t affect cert based authentication but only token-based, but even there not all seem affected (e.g. the test from https://testbed.farm.particle.cz/cgi-bin/se.cgi still work).
An error in the access log of the WebDAV door would look like:
level=WARN ts=2025-12-29T03:06:32.359+0100 event=org.dcache.webdav.request request.method=MKCOL request.url=https://lcg-lrz-http.grid.lrz.de/pnfs/lrz-muenchen.de/data/atlas/dq2/atlasscratchdisk/rucio/group/phys-sm/bb/df response.code=403 socket.remote=[2001:1458:303:27::100:e]:51274 user-agent="libdavix/0.8.10 libcurl/7.76.1" user.sub=f92b9b93-1e65-4402-ab21-178155d8b284@atlas_new user.jti=3def42cd-2af5-48b3-b6df-afb351962a55@atlas_new user.mapped=11001:11000 duration=46
It always happens with MKCOL, but that might simply be because rucio tries to create the dir before uploading the file
The odd thing here is already, that the log entry indicates that a UID/GID mapping would have taken place (user.mapped=11001:11000 , which are the right ones and the parent dir is owned by these), still it gives a 403.
I’ve enabled debug log for gplazma and I think these are the corresponding log entries:
the log contains credentials, so I’ve mailed it to the private RT ticket
as far as I understand that, it means that the mapping should a) be correct, and that the transfers should not have any cert/proxy attached (as @kofemann assumed in the RT ticket), only the token.
The webdav door log in debug mode contains:
2025-12-29T03:06:32.321164+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [] Login attempted: Subject:
2025-12-29T03:06:32.321196+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Principal: Origin[2001:1458:303:27::100:e]
2025-12-29T03:06:32.321238+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Private Credential: BearerTokenCredential[eyJr+{Hash=YlPfftAsf6Q}+L2AQ]
2025-12-29T03:06:32.321282+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [] Login failed with IllegalArgumentException for Subject:
2025-12-29T03:06:32.321322+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Principal: Origin[2001:1458:303:27::100:e]
2025-12-29T03:06:32.321355+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Private Credential: BearerTokenCredential[eyJr+{Hash=YlPfftAsf6Q}+L2AQ]
2025-12-29T03:06:32.321386+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: : Not a macaroon
2025-12-29T03:06:32.321427+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [] Attempting login strategy: org.dcache.services.login.RemoteLoginStrategy
2025-12-29T03:06:32.321461+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [] Login strategy returned Subject:
2025-12-29T03:06:32.321493+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Principal: OidcSubjectPrincipal[f92b9b93-1e65-4402-ab21-178155d8b284@atlas_new]
2025-12-29T03:06:32.321530+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Principal: JwtJtiPrincipal[3def42cd-2af5-48b3-b6df-afb351962a55@atlas_new]
2025-12-29T03:06:32.321562+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Principal: Origin[2001:1458:303:27::100:e]
2025-12-29T03:06:32.321599+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Principal: UidPrincipal[11001]
2025-12-29T03:06:32.321641+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Principal: GidPrincipal[11000,primary]
2025-12-29T03:06:32.321674+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Principal: ExemptFromNamespaceChecks
2025-12-29T03:06:32.321712+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Principal: UserNamePrincipal[atlas-production]
2025-12-29T03:06:32.321750+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: #011Private Credential: BearerTokenCredential[eyJr+{Hash=YlPfftAsf6Q}+L2AQ]
2025-12-29T03:06:32.321784+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] MKCOL :: lcg-lrz-http.grid.lrz.de///pnfs/lrz-muenchen.de/data/atlas/dq2/atlasscratchdisk/rucio/group/phys-sm/bb/df start
2025-12-29T03:06:32.321831+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] process request: host: lcg-lrz-http.grid.lrz.de url: /pnfs/lrz-muenchen.de/data/atlas/dq2/atlasscratchdisk/rucio/group/phys-sm/bb/df
2025-12-29T03:06:32.321865+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] Resolving https://lcg-lrz-http.grid.lrz.de/pnfs/lrz-muenchen.de/data/atlas/dq2/atlasscratchdisk/rucio/group/phys-sm/bb/df
2025-12-29T03:06:32.328633+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] process: resource: org.dcache.webdav.DcacheDirectoryResource
2025-12-29T03:06:32.328727+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] Resolving https://lcg-lrz-http.grid.lrz.de/pnfs/lrz-muenchen.de/data/atlas/dq2/atlasscratchdisk/rucio/group/phys-sm/bb/df
2025-12-29T03:06:32.358147+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] Client indicated response preference: */*
2025-12-29T03:06:32.358351+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] MIME-Type "*/*" has no q-value
2025-12-29T03:06:32.358455+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] Responding with MIME-Type "text/plain; charset=utf-8"
2025-12-29T03:06:32.358607+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] write(array HeapByteBuffer@2da52f4[p=0,l=116,c=116,r=116]={<<<Permission denied for MKC...io/group/phys-sm/bb/df\n>>>})
2025-12-29T03:06:32.358699+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] write(array) s=CLOSING,api=BLOCKED,sc=false,e=null last=true agg=false flush=true async=false, len=116 null
2025-12-29T03:06:32.358811+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] sendResponse info=null content=HeapByteBuffer@30942cdd[p=0,l=116,c=116,r=116]={<<<Permission denied for MKC...io/group/phys-sm/bb/df\n>>>} complete=true committing=true callback=Blocker@20b9292d{null}
2025-12-29T03:06:32.358903+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 2025-12-29 03:06:32+01:00 (webdav.tls_lcg-lrz-dc35) [door:webdav.tls_lcg-lrz-dc35@webdav_lcg-lrz-dc35:AAZHDbEjuBg] COMMIT for /pnfs/lrz-muenchen.de/data/atlas/dq2/atlasscratchdisk/rucio/group/phys-sm/bb/df on HttpChannelOverHttp@15985620{s=HttpChannelState@59c38179{s=HANDLING rs=BLOCKING os=COMMITTED is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=HANDLING,uri=https://lcg-lrz-http.grid.lrz.de/pnfs/lrz-muenchen.de/data/atlas/dq2/atlasscratchdisk/rucio/group/phys-sm/bb/df,age=46}
2025-12-29T03:06:32.358988+01:00 lcg-lrz-dc35 dcache@webdav_lcg-lrz-dc35[14148]: 403 null HTTP/1.1
I'll mail the full log to the aforementioned RT ticket (it also contains tokens).
No idea why it denies it.
Any ideas? This get’s really quite pressing now. :-)
Cheers,
Chris.