Re: [HTCondor-users] CondorCE token subject mapping not working anymore

["Bockelman, Brian" <BBockelman@xxxxxxxxxxxxx>]

Ah-ha!  I know this one.  This is the relevant error:

> 04/18/23 12:24:22.680 (D_SECURITY) SCITOKENS:2:Failed to verify token and generate ACLs: Timeout was reached

The remote endpoint is given 4 seconds to respond to a request for the public key.  Is there potentially some networking issue between you and the remote endpoint?  For example, how long does

curl https://wlcg.cloud.cnaf.infn.it/.well-known/openid-configuration

Take to complete?

Brian

> On Apr 18, 2023, at 5:35 AM, Thomas Hartmann <thomas.hartmann@xxxxxxx> wrote:
> 
> Hi Jamie,
> 
> with the Security logging on debug level 2 I see a bit more. However, it is still not really clear to me, what is the cause. The error is due to the token not being verified and not mapped [1].
> But from my opinion, the existing mapping [2] should match on the token subject.
> 
> Cheers,
>  Thomas
> 
> [1]
> 04/18/23 12:24:18.282 (D_SECURITY) SciToken SSL read is successful.
> 04/18/23 12:24:22.680 (D_SECURITY) SCITOKENS:2:Failed to verify token and generate ACLs: Timeout was reached
> 04/18/23 12:24:22.681 (D_SECURITY:2) AUTHENTICATION: map file already loaded.
> 04/18/23 12:24:22.681 (D_ERROR) Failed to map SCITOKENS authenticated identity '', failing authentication to give another authentication method a go.
> 
> 
> [2]
> root@grid-htcondorce-dev02: [/etc/condor-ce/config.d] cat /etc/condor-ce/mapfiles.d/11_99_token-mapping_DEBUG.conf
> SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,8ec82f26\-a407\-44d7\-aa32\-19cd985cd2d1$/ desyusr009
> SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,1ec796cb\-250b\-479d\-a9e9\-6509995adab0$/ desyusr007
> # SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,bf47638b-5be1-4cda-a156-c2b9d2d1d352$/ desyusr009
> # SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,bc2de59f-c564-4fef-9614-d89c1819426b$/ desyusr009
> SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,737b9ec0\-fb66\-472d\-9ce3\-e943a677464f$/ desyusr008
> # SCITOKENS /^https\:\/\/.*,.*/ desyprd004
> 
> 
>> On 14/04/2023 22.36, Jaime Frey via HTCondor-users wrote:
>>> Can you add the D_SECURITY logging level on the CE daemons? Many SciTokens-related errors are not recorded otherwise.
>>> 
>>>   - Jaime
>>> 
>>>> On Apr 14, 2023, at 9:20 AM, Thomas Hartmann <thomas.hartmann@xxxxxxx> wrote:
>>>> 
>>>> Hi all,
>>>> 
>>>> preparing the migration from CondorCE 5 to GSI-less 6, we noticed that the WLCGToken mapping has been failing for some time.
>>>> 
>>>> Cross-checking on our production v5 CEs, we realized, that token mapping has been failing for some time and that authz fall back to GSI, which had been unnoticed so far.
>>>> Since token authz had worked in the past, I am currently struggling to identify, what change or config broke the mapping.
>>>> 
>>>> Starting with a fresh CondorCE installation from scratch and adding configs & mappings, I have not been able to get the token mapping working again.
>>>> 
>>>> It is a CondorCE v6, Condor v10.4 installation on EL7 [1].
>>>> 
>>>> Mapping rules are tokens only with a test client mapped to (existing) local users [2], so that tokens like [3] should get mapped onto the local `desyusr007`.
>>>> 
>>>> However, trace and write pings always fail due to an allegedly broken mapping [4]. Judging from the SchedLog and AuditLog [5,6] the tokens are received and parsed - but then something(??) is not to the CE's liking :-/
>>>> 
>>>> Submitting a job to a friendly site's CE works with the mapping rule as of [2] deployed - so I would rule out an issue with the client/tokens. The other way round, a job from the remote site (running under a token from a client of the other site) fails, so that it is most probable something local with my CE.
>>>> 
>>>> Also a very trusting catch all map rule
>>>>   SCITOKENS /^https\:\/\/.*,.*/ desyprd004
>>>> failed.
>>>> 
>>>> Daemon output is already on `ALL_DEBUG = D_FULLDEBUG` but maybe there is a way to increase the audit logging to get an idea, why the matching fails?
>>>> 
>>>> SELinux or so seems not involved so far.
>>>> 
>>>> Maybe someone has an idea, where I might find the underlying issue? (probably something system related and not directly CondorCE config specific??).
>>>> 
>>>> Cheers and thanks for any idea,
>>>>   Thomas
>>>> 
>>>> [1]
>>>> condor-procd-10.4.0-1.el7.x86_64
>>>> condor-classads-10.4.0-1.el7.x86_64
>>>> python2-condor-10.4.0-1.el7.x86_64
>>>> htcondor-ce-6.0.0-1.el7.noarch
>>>> condor-stash-plugin-6.10.0-1.x86_64
>>>> python3-condor-10.4.0-1.el7.x86_64
>>>> htcondor-ce-client-6.0.0-1.el7.noarch
>>>> condor-externals-9.0.15-1.el7.x86_64
>>>> condor-10.4.0-1.el7.x86_64
>>>> condor-blahp-10.4.0-1.el7.x86_64
>>>> htcondor-ce-apel-6.0.0-1.el7.noarch
>>>> htcondor-release-10.x-1.el7.noarch
>>>> 
>>>> [2]
>>>>> grep include /etc/condor-ce/condor_mapfile
>>>> @include /etc/condor-ce/mapfiles.d/
>>>> @include /usr/share/condor-ce/mapfiles.d/
>>>> 
>>>>> cat /etc/condor-ce/mapfiles.d/11_99_token-mapping_DEBUG.conf
>>>> SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,8ec82f26\-a407\-44d7\-aa32\-19cd985cd2d1$/ desyusr009
>>>> SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,1ec796cb\-250b\-479d\-a9e9\-6509995adab0$/ desyusr007
>>>> # SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,bf47638b-5be1-4cda-a156-c2b9d2d1d352$/ desyusr009
>>>> # SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,bc2de59f-c564-4fef-9614-d89c1819426b$/ desyusr009
>>>> SCITOKENS /^https:\/\/wlcg\.cloud\.cnaf\.infn\.it\/,737b9ec0\-fb66\-472d\-9ce3\-e943a677464f$/ desyusr008
>>>> 
>>>> 
>>>> [3]
>>>> {
>>>>   "wlcg.ver": "1.0",
>>>>   "sub": "1ec796cb-250b-479d-a9e9-6509995adab0",
>>>>   "aud": "https://wlcg.cern.ch/jwt/v1/any";,
>>>>   "nbf": 1681479491,
>>>>   "scope": "openid compute.create offline_access compute.read compute.cancel compute.modify",
>>>>   "iss": "https://wlcg.cloud.cnaf.infn.it/";,
>>>>   "exp": 1681483091,
>>>>   "iat": 1681479491,
>>>>   "jti": "78d1ad5a-2be0-4367-88bb-6a9f59939bc5",
>>>>   "client_id": "8ec82f26-a407-44d7-aa32-19cd985cd2d1"
>>>> }
>>>> 
>>>> [4]
>>>>> export _condor_SEC_CLIENT_AUTHENTICATION_METHODS=SCITOKENS
>>>>> export BEARER_TOKEN_FILE=/tmp/token_$(id -u)
>>>>> date; oidc-token -f --time=720 belle-desydebug-group > /tmp/token_$(id -u); condor_ce_trace --debug grid-htcondorce-dev.desy.de
>>>> Fri Apr 14 15:46:32 CEST 2023
>>>> ...
>>>> 04/14/23 15:46:32 SharedPortClient: sent connection request to daemon at <131.169.223.131:9619> for shared port id schedd_1298351_f7d0
>>>> 04/14/23 15:46:32 Looking for token in file /tmp/token_14053
>>>> 04/14/23 15:46:37 SECMAN: required authentication with daemon at <131.169.223.131:9619> failed, so aborting command DC_SEC_QUERY.
>>>> ********************************************************************************
>>>> 2023-04-14 15:46:41 ERROR: WRITE access failed for scheduler daemon at
>>>> <131.169.223.131:9619?addrs=131.169.223.131-9619+[2001-638-700-10df--
>>>> 1-83]-9619&alias=grid-htcondorce-dev.desy.de&noUDP&sock=schedd_1298351_f7d0>.
>>>> WRITE failed!
>>>> AUTHENTICATE:1003:Failed to authenticate with any method
>>>> AUTHENTICATE:1004:Failed to authenticate using SCITOKENS
>>>> 
>>>> 
>>>> ********************************************************************************
>>>> 
>>>> 
>>>> [5]
>>>> 04/14/23 15:46:32 Examining SciToken with payload {"wlcg.ver":"1.0","sub":"1ec796cb-250b-479d-a9e9-6509995adab0","aud":"https:\/\/wlcg.cern.ch\/jwt\/v1\/any","nbf":1681479491,"scope":"openid compute.create offline_access compute.read compute.cancel compute.modify","iss":"https:\/\/wlcg.cloud.cnaf.infn.it\/","exp":1681483091,"iat":1681479491,"jti":"78d1ad5a-2be0-4367-88bb-6a9f59939bc5","client_id":"8ec82f26-a407-44d7-aa32-19cd985cd2d1"}.
>>>> 04/14/23 15:46:37 DC_AUTHENTICATE: required authentication of 131.169.223.90 failed: AUTHENTICATE:1003:Failed to authenticate with any method|AUTHENTICATE:1004:Failed to authenticate using SCITOKENS
>>>> 04/14/23 15:46:37 Examining SciToken with payload {"wlcg.ver":"1.0","sub":"1ec796cb-250b-479d-a9e9-6509995adab0","aud":"https:\/\/wlcg.cern.ch\/jwt\/v1\/any","nbf":1681479491,"scope":"openid compute.create offline_access compute.read compute.cancel compute.modify","iss":"https:\/\/wlcg.cloud.cnaf.infn.it\/","exp":1681483091,"iat":1681479491,"jti":"78d1ad5a-2be0-4367-88bb-6a9f59939bc5","client_id":"8ec82f26-a407-44d7-aa32-19cd985cd2d1"}.
>>>> 04/14/23 15:46:41 DC_AUTHENTICATE: required authentication of 131.169.223.90 failed: AUTHENTICATE:1003:Failed to authenticate with any method|AUTHENTICATE:1004:Failed to authenticate using SCITOKENS
>>>> 04/14/23 15:46:49 Evaluated periodic expressions in 0.000s, scheduling next run in 61s
>>>> 
>>>> 
>>>> [6]
>>>> 04/14/23 15:46:32 (cid:21) Examining SciToken with payload {"wlcg.ver":"1.0","sub":"1ec796cb-250b-479d-a9e9-6509995adab0","aud":"https:\/\/wlcg.cern.ch\/jwt\/v1\/any","nbf":1681479491,"scope":"openid compute.create offline_access compute.read compute.cancel compute.modify","iss":"https:\/\/wlcg.cloud.cnaf.infn.it\/","exp":1681483091,"iat":1681479491,"jti":"78d1ad5a-2be0-4367-88bb-6a9f59939bc5","client_id":"8ec82f26-a407-44d7-aa32-19cd985cd2d1"}.
>>>> 04/14/23 15:46:37 (cid:23) Examining SciToken with payload {"wlcg.ver":"1.0","sub":"1ec796cb-250b-479d-a9e9-6509995adab0","aud":"https:\/\/wlcg.cern.ch\/jwt\/v1\/any","nbf":1681479491,"scope":"openid compute.create offline_access compute.read compute.cancel compute.modify","iss":"https:\/\/wlcg.cloud.cnaf.infn.it\/","exp":1681483091,"iat":1681479491,"jti":"78d1ad5a-2be0-4367-88bb-6a9f59939bc5","client_id":"8ec82f26-a407-44d7-aa32-19cd985cd2d1"}.
>>>> _______________________________________________
>>>> HTCondor-users mailing list
>>>> To unsubscribe, send a message to htcondor-users-request@xxxxxxxxxxx with a
>>>> subject: Unsubscribe
>>>> You can also unsubscribe by visiting
>>>> https://lists.cs.wisc.edu/mailman/listinfo/htcondor-users
>>>> 
>>>> The archives can be found at:
>>>> https://lists.cs.wisc.edu/archive/htcondor-users/
>>> 
>>> 
>>> _______________________________________________
>>> HTCondor-users mailing list
>>> To unsubscribe, send a message to htcondor-users-request@xxxxxxxxxxx with a
>>> subject: Unsubscribe
>>> You can also unsubscribe by visiting
>>> https://lists.cs.wisc.edu/mailman/listinfo/htcondor-users
>>> 
>>> The archives can be found at:
>>> https://lists.cs.wisc.edu/archive/htcondor-users/
> <CEclient.txt><SchedLog.20230416>_______________________________________________
> HTCondor-users mailing list
> To unsubscribe, send a message to htcondor-users-request@xxxxxxxxxxx with a
> subject: Unsubscribe
> You can also unsubscribe by visiting
> https://lists.cs.wisc.edu/mailman/listinfo/htcondor-users
> 
> The archives can be found at:
> https://lists.cs.wisc.edu/archive/htcondor-users/