Mailing List ArchivesAuthenticated access |
![[Computer Systems Lab]](http://www.cs.wisc.edu/pics/csl_logo.gif){kind=logo}
|
Mailing List ArchivesAuthenticated access |
|
Hi gurus !
We (CMS) are encountering an authentication issue when
using condor_store_cred to send an Oauth2 credential
from a send host (S) to a receiveing AP where it will be
used to provide auth. tokens to jobs submitted by user "crabtw".
S authenticates with bearer token when connecting to AP's credd.
CredLog on AP reports
02/18/26 10:30:58 (pid:319805) DC_AUTHENTICATE: authentication of <[2001:1458:d00:4e::100:498]:15651> did not result in a valid mapped user name, which is required for this command (479 STORE_CRED), so aborting. 02/18/26 10:30:58 (pid:319805) DC_AUTHENTICATE: reason for authentication failure: AUTHENTICATE:1006:exceeded 1771407058 deadline during authentication|SCITOKENS:2:Failed to verify token and generate ACLs: Timeout when loading the OIDC metadata.
where 2001:1458:d00:4e::100:498 is indeed our sender (vocms900.cern.ch)
We are quite puzzled because this setup used to work
until last week and now we can't find out what may have
changed. Hopefully experts can tell us where else to look
or how to enable more diagnostic. We run credd in AP
with CREDD_DEBUG = D_FULLDEBUG,D_PID,D_SECURITY
Below I report logs from S and the AP's CredLog when
condor_store_cred
was issued on S. Tha command is executed in a script which also
- prepares the tokens
- sets in the environment
BEARER_TOKEN_FILE to point to the token obtained via
htgettoken
_condor_SEC_CLIENT_AUTHENTICATION_METHODS" = "SCITOKENS"
_condor_TOOL_DEBUG = "D_FULLDEBUG,D_SECURITY"
The BEARER_TOKEN looks like this (from httokendecode)
{
"sub": "58ba8516-2e94-4888-bce5-0187f7b4ebb9",
"iss": "https://cms-auth.cern.ch/",
"client_id": "48620efa-e001-4c1d-84fc-4640d9498a11",
"wlcg.ver": "1.0",
"aud": "https://wlcg.cern.ch/jwt/v1/any",
"nbf": "Mon Feb 16 12:36:16 PM CET 2026",
"scope": "condor:/WRITE openid storage.create:/store/temp/user
offline_access profile storage.read:/
storage.modify:/store/temp/user email wlcg",
"auth_time": "Mon Feb 16 12:37:13 PM CET 2026",
"exp": "Sat Feb 21 12:37:16 AM CET 2026",
"iat": "Mon Feb 16 12:37:16 PM CET 2026",
"jti": "4655899b-e979-409e-9550-30b26529747b",
"wlcg.groups": [
"/cms",
"/cms/itcms"
]
}
The credential to be stored looks like
{
"vault_token": "s.RwVr75BqIob4HHNMCGNOoukF",
"vault_url":
"https://dwdvault.cern.ch:8200/v1/secret/oauth/creds/cms/crabint1:crab"
}
In the AP we have this line in /etc/condor/certs/condor_mapfile
SCITOKENS
"https://cms-auth.cern.ch/,58ba8516-2e94-4888-bce5-0187f7b4ebb9"
crabtw
which AFAWU should map the incoming request from S to local user
crabtw
The incoming S host (vocms900.cern.ch) is allowed via
condor_config_val CREDD.ALLOW_WRITE
vocms900.cern.ch, crab-sched-901.cern.ch, crab-sched-901.cern.ch
We also checked on AP
* SEC_DEFAULT_AUTHENTICATION_METHODS = SCITOKENS,FS,IDTOKENS
* SEC_ENABLE_SCITOKEN_EXCHANGE = true
* SEC_CREDENTIAL_GETTOKEN_OPTS = -a dwdvault.cern.ch
Thanks for any help, guidance, suggestions !
We will happily provide more details and/or access to S and AP
if needed.
Stefano and others at CMS
And now longish but full logs from sender and receiver side:
S side
2026-Feb-18 10:30:34 [I] Acquiring Kerberos TGT for account crabint1 ... 2026-Feb-18 10:30:37 [N] Kerberos TGT for crabint1 acquired 2026-Feb-18 10:30:37 [I] Acquiring vault and bearer token for crabint1 from dwdvault.cern.ch:8200 ... 2026-Feb-18 10:30:38 [N] Vault and bearer token from dwdvault.cern.ch:8200 acquired 2026-Feb-18 10:30:38 [I] Storing vault token in account crabtw@cms at credd crab-sched-901.cern.ch 2026-Feb-18 10:30:58 [E] /usr/sbin/condor_store_cred -d -u crabtw@cms -s cms_crab -i /tmp/vtkn_mtb2421722.json add-oauth 02/18/26 10:30:38 Reading condor configuration from '/etc/condor/condor_config' 02/18/26 10:30:38 STORE_CRED: In mode 40 'add', user is "crabtw@cms" 02/18/26 10:30:38 Starting a command on a REMOTE schedd or credd 02/18/26 10:30:38 Will use TCP to update collector vocms4100.cern.ch <[2001:1458:301:47::100:12]:9618?alias=vocms4100.cern.ch> 02/18/26 10:30:38 Trying to query collector <[2001:1458:301:47::100:12]:9618?alias=vocms4100.cern.ch> 02/18/26 10:30:38 SECMAN: command 74 QUERY_GENERIC_ADS to collector at <[2001:1458:301:47::100:12]:9618> from TCP port 8295 (blocking). 02/18/26 10:30:38 SECMAN: generating AES key for session with collector at <[2001:1458:301:47::100:12]:9618>... 02/18/26 10:30:38 SESSION: client duplicated AES to BLOWFISH key for UDP. 02/18/26 10:30:38 SECMAN: added session vocms4100:2528793:1771407038:172706210 to cache for 60 seconds (3600s lease). 02/18/26 10:30:38 SECMAN: startCommand succeeded. 02/18/26 10:30:38 SharedPortClient: sent connection request to credd crab-sched-901.cern.ch for shared port id credd_319805_4da6 02/18/26 10:30:38 SECMAN: command 479 STORE_CRED to credd crab-sched-901.cern.ch from TCP port 15651 (blocking). 02/18/26 10:30:38 SECMAN: new session, doing initial authentication. 02/18/26 10:30:38 SECMAN: Auth methods: SCITOKENS 02/18/26 10:30:38 AUTHENTICATE: setting timeout for <188.185.124.196:4080?addrs=[2001-1458-d00-4a--100-486]-4080+188.185.124.196-4080&alias=crab-sched-901.cern.ch&noUDP&sock=credd_319805_4da6> to 20. 02/18/26 10:30:38 HANDSHAKE: in handshake(my_methods = 'SCITOKENS') 02/18/26 10:30:38 HANDSHAKE: handshake() - i am the client 02/18/26 10:30:38 HANDSHAKE: sending (methods == 4096) to server 02/18/26 10:30:38 HANDSHAKE: server replied (method = 4096) 02/18/26 10:30:38 CIPHERLIST: 'ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA:DHE-RSA-AES256-SHA256:DHE-RSA-AES256-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC3-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:DES-CBC3-SHA:!DSS' 02/18/26 10:30:38 SSL Auth: Trying to connect. 02/18/26 10:30:38 SSL Auth: SSL: trying to continue reading. 02/18/26 10:30:38 SSL Auth: Trying to connect. 02/18/26 10:30:38 SSL Auth: SSL: trying to continue reading. 02/18/26 10:30:38 SSL Auth: Trying to connect. 02/18/26 10:30:38 SSL Auth: post_connection_check. 02/18/26 10:30:38 SSL host check: host alias crab-sched-901.cern.ch matches certificate SAN crab-sched-901.cern.ch. 02/18/26 10:30:38 SSL Auth: SSL: continue read/write. 02/18/26 10:30:58 SSL Auth: Server has rejected our token! 02/18/26 10:30:58 AUTHENTICATE: method 4096 (SCITOKENS) failed. 02/18/26 10:30:58 AUTHENTICATE: exceeded deadline 1771407058 02/18/26 10:30:58 Authentication was a FAILURE. 02/18/26 10:30:58 SECMAN: required authentication with credd crab-sched-901.cern.ch failed, so aborting command STORE_CRED. 02/18/26 10:30:58 ERROR: AUTHENTICATE:1006:exceeded 1771407058 deadline during authentication|AUTHENTICATE:1004:Failed to authenticate using SCITOKENS 02/18/26 10:30:58 STORE_CRED: Failed to start STORE_CRED command. Unable to contact credd crab-sched-901.cern.ch Account: crabtw@cms CredType: oauth Operation failed. Make sure your ALLOW_WRITE setting includes this host. condor_store_cred error, rc=1 2026-Feb-18 10:30:58 [C] Failed to store vault token for crabtw at credd crab-sched-901.cern.ch, ManageToken entry CRAB-Test BEARER_TOKEN_FILE : tmp/bt_mtb2421722 [cmstokn@vocms900 bin]$
AP side:
02/18/26 10:30:38 (pid:319805) DC_AUTHENTICATE: received DC_AUTHENTICATE from <[2001:1458:d00:4e::100:498]:15651> 02/18/26 10:30:38 (pid:319805) SECMAN: new session, doing initial authentication. 02/18/26 10:30:38 (pid:319805) Returning to DC while we wait for socket to authenticate. 02/18/26 10:30:38 (pid:319805) AUTHENTICATE: setting timeout for (unknown) to 20. 02/18/26 10:30:38 (pid:319805) HANDSHAKE: in handshake(my_methods = 'SCITOKENS') 02/18/26 10:30:38 (pid:319805) HANDSHAKE: handshake() - i am the server 02/18/26 10:30:38 (pid:319805) HANDSHAKE: client sent (methods == 4096) 02/18/26 10:30:38 (pid:319805) HANDSHAKE: i picked (method == 4096) 02/18/26 10:30:38 (pid:319805) HANDSHAKE: client received (method == 4096) 02/18/26 10:30:38 (pid:319805) CADIR: '/etc/grid-security/certificates' 02/18/26 10:30:38 (pid:319805) CERTFILE: '/etc/grid-security/hostcert.pem' 02/18/26 10:30:38 (pid:319805) KEYFILE: '/etc/grid-security/hostkey.pem' 02/18/26 10:30:38 (pid:319805) CIPHERLIST: 'ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA:DHE-RSA-AES256-SHA256:DHE-RSA-AES256-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC3-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:DES-CBC3-SHA:!DSS' 02/18/26 10:30:38 (pid:319805) ALLOW_PROXY: 0 02/18/26 10:30:38 (pid:319805) Will return to DC because authentication is incomplete. 02/18/26 10:30:38 (pid:319805) SSL Auth: Trying to accept. 02/18/26 10:30:38 (pid:319805) SSL Auth: SSL: trying to continue reading. 02/18/26 10:30:38 (pid:319805) AUTHENTICATE: auth would still block 02/18/26 10:30:38 (pid:319805) Will return to DC to continue authentication.. 02/18/26 10:30:38 (pid:319805) SSL Auth: Trying to accept. 02/18/26 10:30:38 (pid:319805) SSL Auth: SSL: trying to continue reading. 02/18/26 10:30:38 (pid:319805) SSL Auth: Trying to accept. 02/18/26 10:30:38 (pid:319805) SSL Auth: SSL: trying to continue reading. 02/18/26 10:30:38 (pid:319805) SSL Auth: Trying to accept. 02/18/26 10:30:38 (pid:319805) SSL Auth: SSL: trying to continue reading. 02/18/26 10:30:38 (pid:319805) AUTHENTICATE: auth would still block 02/18/26 10:30:38 (pid:319805) Will return to DC to continue authentication.. 02/18/26 10:30:38 (pid:319805) SSL Auth: Trying to accept. 02/18/26 10:30:38 (pid:319805) SSL Auth: SSL: trying to continue reading. 02/18/26 10:30:38 (pid:319805) SSL Auth: Trying to accept. 02/18/26 10:30:38 (pid:319805) SSL Auth: post_connection_check. 02/18/26 10:30:38 (pid:319805) SSL Auth: Anonymous client is allowed; not checking. 02/18/26 10:30:38 (pid:319805) AUTHENTICATE: auth would still block 02/18/26 10:30:38 (pid:319805) Will return to DC to continue authentication.. 02/18/26 10:30:58 (pid:319805) SCITOKENS error: Failed to verify token and generate ACLs: Timeout when loading the OIDC metadata. 02/18/26 10:30:58 (pid:319805) SSL Auth: SciToken Authentication failed at token exchange. 02/18/26 10:30:58 (pid:319805) AUTHENTICATE: exceeded deadline 1771407058 02/18/26 10:30:58 (pid:319805) Authentication was a FAILURE. 02/18/26 10:30:58 (pid:319805) DC_AUTHENTICATE: authentication of <[2001:1458:d00:4e::100:498]:15651> did not result in a valid mapped user name, which is required for this command (479 STORE_CRED), so aborting. 02/18/26 10:30:58 (pid:319805) DC_AUTHENTICATE: reason for authentication failure: AUTHENTICATE:1006:exceeded 1771407058 deadline during authentication|SCITOKENS:2:Failed to verify token and generate ACLs: Timeout when loading the OIDC metadata.