hautreux / auks

Kerberos credential support for batch environments
Other
20 stars 18 forks source link

What am I doing wrong. Auks API request failed : auks api : request processing failed #42

Closed trenta closed 4 years ago

trenta commented 4 years ago

I've had AUKS and SLURM running successfully on CenOS 7 and still is.

I've built a new cluster using RHEL 7

Most things are controlled on these servers by puppet so config and setting should be pretty much the same.

Kerberos is working on these machines fine for nfs shares so I'm assuming that's not the issue.

I can't successfully run auks -p on any node but for now just trying on the master node.

[tanderson@slurm-cont01 ~]$ sudo klist -fna Ticket cache: FILE:/tmp/krb5cc_0 Default principal: SLURM-CONT01$@AD.SVI.EDU.AU

Valid starting Expires Service principal 01/07/20 20:33:11 02/07/20 06:33:11 krbtgt/AD.SVI.EDU.AU@AD.SVI.EDU.AU renew until 29/09/20 20:33:11, Flags: RIA Addresses: (none) 01/07/20 20:33:17 02/07/20 06:33:11 host/slurm-cont01.svi.edu.au@AD.SVI.EDU.AU renew until 29/09/20 20:33:11, Flags: RA Addresses: (none) [tanderson@slurm-cont01 ~]$ klist -fna Ticket cache: FILE:/tmp/krb5cc_1001 Default principal: tanderson@AD.SVI.EDU.AU

Valid starting Expires Service principal 01/07/20 20:34:20 02/07/20 20:34:17 krbtgt/AD.SVI.EDU.AU@AD.SVI.EDU.AU renew until 29/09/20 20:34:17, Flags: RIA Addresses: (none) 01/07/20 20:34:32 02/07/20 06:34:32 host/slurm-cont01.svi.edu.au@AD.SVI.EDU.AU renew until 29/09/20 20:34:17, Flags: RA Addresses: (none)

Here are some very verbose logs. Thanks for any help.

[tanderson@slurm-cont01 ~]$ auks -vvv -p Wed Jul 1 20:47:08 2020 [INFO2] [euid=1001,pid=8880] auks_engine: initializing engine from 'common' block of file /etc/auks/auks.conf Wed Jul 1 20:47:08 2020 [INFO2] [euid=1001,pid=8880] auks_engine: initializing engine from 'api' block of file /etc/auks/auks.conf Wed Jul 1 20:47:08 2020 [INFO2] [euid=1001,pid=8880] auks_engine: initializing engine from 'renewer' block of file /etc/auks/auks.conf Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine primary daemon is 'slurm-cont01.svi.edu.au' Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine primary daemon address is 'slurm-cont01.svi.edu.au' Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine primary daemon port is 12345 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine primary daemon principal is host/slurm-cont01.svi.edu.au@AD.SVI.EDU.AU Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine secondary daemon is 'localhost' Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine secondary daemon address is 'localhost' Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine secondary daemon port is 12345 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine secondary daemon principal is Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine logfile is /tmp/auksapi.log Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine loglevel is 10 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine debugfile is /tmp/auksapi.log Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine debuglevel is 10 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine retry number is 3 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine timeout is 10 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine delay is 3 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine NAT traversal mode is disabled Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine renewer_logfile is /var/log/auksdrenewer.log Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine renewer_loglevel is 10 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine renewer_debugfile is /var/log/auksdrenewer.log Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine renewer_debuglevel is 10 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine renewer delay is 60 Wed Jul 1 20:47:08 2020 [INFO3] [euid=1001,pid=8880] auks_engine: engine renewer min cred lifetime is 600 Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_api: starting retry 1 of 3 Wed Jul 1 20:47:08 2020 [INFO7] [euid=1001,pid=8880] xstream: socket creation succeed Wed Jul 1 20:47:08 2020 [INFO7] [euid=1001,pid=8880] xstream: socket non-blocking flag is now set Wed Jul 1 20:47:08 2020 [INFO7] [euid=1001,pid=8880] xstream: connect (10.80.0.141:12345) succeed while polling Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_api: successfully connected to auks server slurm-cont01.svi.edu.au:12345 Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: local endpoint stream 4 informations request succeed Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: remote endpoint stream 4 informations request succeed Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: remote host is 10.80.0.141 Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: context initialization succeed Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: connection authentication context initialisation succeed Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: authentication context addrs set up succeed Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: default kstream initialisation succeed Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: kstream basic initialisation succeed Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: ccache initialisation succeed Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: client kstream initialisation succeed Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: authentication failed : Server rejected authentication (during sendauth exchange) Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_api: authentication failed : krb5 sendauth stage failed (client side) Wed Jul 1 20:47:08 2020 [INFO7] [euid=1001,pid=8880] xstream: socket creation succeed Wed Jul 1 20:47:08 2020 [INFO7] [euid=1001,pid=8880] xstream: socket non-blocking flag is now set Wed Jul 1 20:47:08 2020 [INFO7] [euid=1001,pid=8880] xstream: connect (127.0.0.1:12345) failed while polling : Connection refused Wed Jul 1 20:47:08 2020 [INFO7] [euid=1001,pid=8880] xstream: socket creation succeed Wed Jul 1 20:47:08 2020 [INFO7] [euid=1001,pid=8880] xstream: socket non-blocking flag is now set Wed Jul 1 20:47:08 2020 [INFO7] [euid=1001,pid=8880] xstream: connect (127.0.0.1:12345) failed while polling : Connection refused Wed Jul 1 20:47:08 2020 [INFO4] [euid=1001,pid=8880] auks_api: unable to connect to auks server localhost:12345 Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_api: starting retry 2 of 3 Wed Jul 1 20:47:11 2020 [INFO7] [euid=1001,pid=8880] xstream: socket creation succeed Wed Jul 1 20:47:11 2020 [INFO7] [euid=1001,pid=8880] xstream: socket non-blocking flag is now set Wed Jul 1 20:47:11 2020 [INFO7] [euid=1001,pid=8880] xstream: connect (10.80.0.141:12345) succeed while polling Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_api: successfully connected to auks server slurm-cont01.svi.edu.au:12345 Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: local endpoint stream 4 informations request succeed Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: remote endpoint stream 4 informations request succeed Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: remote host is 10.80.0.141 Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: context initialization succeed Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: connection authentication context initialisation succeed Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: authentication context addrs set up succeed Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: default kstream initialisation succeed Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: kstream basic initialisation succeed Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: ccache initialisation succeed Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: client kstream initialisation succeed Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: authentication failed : Server rejected authentication (during sendauth exchange) Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_api: authentication failed : krb5 sendauth stage failed (client side) Wed Jul 1 20:47:11 2020 [INFO7] [euid=1001,pid=8880] xstream: socket creation succeed Wed Jul 1 20:47:11 2020 [INFO7] [euid=1001,pid=8880] xstream: socket non-blocking flag is now set Wed Jul 1 20:47:11 2020 [INFO7] [euid=1001,pid=8880] xstream: connect (127.0.0.1:12345) failed while polling : Connection refused Wed Jul 1 20:47:11 2020 [INFO7] [euid=1001,pid=8880] xstream: socket creation succeed Wed Jul 1 20:47:11 2020 [INFO7] [euid=1001,pid=8880] xstream: socket non-blocking flag is now set Wed Jul 1 20:47:11 2020 [INFO7] [euid=1001,pid=8880] xstream: connect (127.0.0.1:12345) failed while polling : Connection refused Wed Jul 1 20:47:11 2020 [INFO4] [euid=1001,pid=8880] auks_api: unable to connect to auks server localhost:12345 Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_api: starting retry 3 of 3 Wed Jul 1 20:47:14 2020 [INFO7] [euid=1001,pid=8880] xstream: socket creation succeed Wed Jul 1 20:47:14 2020 [INFO7] [euid=1001,pid=8880] xstream: socket non-blocking flag is now set Wed Jul 1 20:47:14 2020 [INFO7] [euid=1001,pid=8880] xstream: connect (10.80.0.141:12345) succeed while polling Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_api: successfully connected to auks server slurm-cont01.svi.edu.au:12345 Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: local endpoint stream 4 informations request succeed Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: remote endpoint stream 4 informations request succeed Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: remote host is 10.80.0.141 Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: context initialization succeed Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: connection authentication context initialisation succeed Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: authentication context addrs set up succeed Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: default kstream initialisation succeed Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: kstream basic initialisation succeed Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: ccache initialisation succeed Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: client kstream initialisation succeed Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_krb5_stream: authentication failed : Server rejected authentication (during sendauth exchange) Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_api: authentication failed : krb5 sendauth stage failed (client side) Wed Jul 1 20:47:14 2020 [INFO7] [euid=1001,pid=8880] xstream: socket creation succeed Wed Jul 1 20:47:14 2020 [INFO7] [euid=1001,pid=8880] xstream: socket non-blocking flag is now set Wed Jul 1 20:47:14 2020 [INFO7] [euid=1001,pid=8880] xstream: connect (127.0.0.1:12345) failed while polling : Connection refused Wed Jul 1 20:47:14 2020 [INFO7] [euid=1001,pid=8880] xstream: socket creation succeed Wed Jul 1 20:47:14 2020 [INFO7] [euid=1001,pid=8880] xstream: socket non-blocking flag is now set Wed Jul 1 20:47:14 2020 [INFO7] [euid=1001,pid=8880] xstream: connect (127.0.0.1:12345) failed while polling : Connection refused Wed Jul 1 20:47:14 2020 [INFO4] [euid=1001,pid=8880] auks_api: unable to connect to auks server localhost:12345 Wed Jul 1 20:47:14 2020 [INFO3] [euid=1001,pid=8880] auks_api: ping request processing failed : auks api : connection failed Auks API request failed : auks api : request processing failed

trenta commented 4 years ago

This was my bad configuration.

In auks.conf as the PrimaryPrincipal I had host/fqdn@REALM The domain in the fqdn doesn't match the REALM. So the actual entry was

PrimaryPrincipal = "host/slurm-cont01.svi.edu.au@AD.SVI.EDU.AU" ;

and the fix was to change to

PrimaryPrincipal = "host/slurm-cont01.ad.svi.edu.au@AD.SVI.EDU.AU" ;