ubuntu / authd

Authentication daemon for external Brokers
GNU Lesser General Public License v3.0
123 stars 12 forks source link

Issue: SSH login closes connection #665

Open RandyParedis opened 1 day ago

RandyParedis commented 1 day ago

Is there an existing issue for this?

Describe the issue

I am running an Ubuntu 24.04.1 server for which I would like to allow SSO. I have followed the installation and configuration instructions in the Wiki, but I cannot log into the server. Whenever I have entered my local password, I get kicked out of the SSH connection. What am I missing?

Steps to reproduce

  1. Create an Ubuntu 24.04.1 instance.
  2. Follow the installation and configuration instruction instructions.

First SSH login:

  1. Select the Entra ID broker
  2. Log in through the devicelogin website.
  3. Create a local password.
  4. This is where I get kicked out.

Sequential SSH login:

  1. Select the Entra ID broker
  2. Enter the local password.
  3. Here, I again get kicked out...

System information and logs

authd version

authd   0.3.6

authd-msentraid broker version

name:      authd-msentraid
summary:   MSEntra ID broker for authd
publisher: Canonical**
store-url: https://snapcraft.io/authd-msentraid
license:   GPL-3.0
description: |
  This is the MS Entra ID broker snap for authd  to provide MS Entra ID OIDC
  based authentication on Ubuntu with authd.
services:
  authd-msentraid: simple, enabled, active
snap-id:      vS3oJLMss6lgWwoFcPqYDUA2HB20I1Dc
tracking:     0.x/stable
refresh-date: today at 15:40 UTC
channels:
  0.x/stable:    0.1+4fe9826.0f76acc 2024-10-02 (51) 18MB -
  0.x/candidate: ^
  0.x/beta:      ^
  0.x/edge:      0.1+b5b8633.8c6c10d 2024-11-19 (82) 18MB -
installed:       0.1+4fe9826.0f76acc            (51) 18MB -

gnome-shell version

gnome-shell:
  Installed: (none)
  Candidate: 46.3.1-1ubuntu1~24.04.1authd2
  Version table:
     46.3.1-1ubuntu1~24.04.1authd2 500
        500 https://ppa.launchpadcontent.net/ubuntu-enterprise-desktop/authd/ubuntu noble/main amd64 Packages
     46.0-0ubuntu6~24.04.5 500
        500 http://us.archive.ubuntu.com/ubuntu noble-updates/main amd64 Packages
     46.0-0ubuntu6~24.04.3 500
        500 http://us.archive.ubuntu.com/ubuntu noble-security/main amd64 Packages
     46.0-0ubuntu5 500
        500 http://us.archive.ubuntu.com/ubuntu noble/main amd64 Packages

Distribution

Distributor ID: Ubuntu
Description:    Ubuntu 24.04.1 LTS
Release:        24.04
Codename:       noble

Logs

[  716.603304] studento systemd[1]: Starting authd.service - Authd daemon service...
[  716.623368] studento authd[3579]: WARNING Broker configuration directory "/etc/authd/brokers.d/" does not exist, only local broker will be available
[  716.634993] studento systemd[1]: Started authd.service - Authd daemon service.
[  716.635735] studento authd[3579]: 2024/12/02 15:40:23 WARN rpc error: code = NotFound desc =
[  716.636638] studento authd[3579]: 2024/12/02 15:40:23 WARN rpc error: code = NotFound desc =
[  716.645074] studento authd[3579]: 2024/12/02 15:40:23 WARN rpc error: code = NotFound desc =
[  716.645573] studento authd[3579]: 2024/12/02 15:40:23 WARN rpc error: code = NotFound desc =
[  716.734119] studento authd[3579]: 2024/12/02 15:40:23 WARN rpc error: code = NotFound desc =
[  716.734627] studento authd[3579]: 2024/12/02 15:40:23 WARN rpc error: code = NotFound desc =
[  722.170880] studento authd[3579]: 2024/12/02 15:40:29 WARN rpc error: code = NotFound desc =
[  723.469367] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[  723.904178] studento authd-msentraid.authd-msentraid[4411]: time=2024-12-02T15:40:31.099Z level=ERROR msg="config file has invalid values, did you edit the file \"/var/snap/authd-msentraid/51/broker.conf\"?\nfound invalid character in section \"oidc\", key \"issuer\"\nfound invalid character in section \"oidc\", key \"client_id\""
[  723.905716] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Main process exited, code=exited, status=1/FAILURE
[  723.905894] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Failed with result 'exit-code'.
[  724.087169] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Scheduled restart job, restart counter is at 1.
[  724.096258] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[  724.129649] studento authd-msentraid.authd-msentraid[4441]: time=2024-12-02T15:40:31.325Z level=ERROR msg="config file has invalid values, did you edit the file \"/var/snap/authd-msentraid/51/broker.conf\"?\nfound invalid character in section \"oidc\", key \"issuer\"\nfound invalid character in section \"oidc\", key \"client_id\""
[  724.130694] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Main process exited, code=exited, status=1/FAILURE
[  724.130871] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Failed with result 'exit-code'.
[  724.336955] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Scheduled restart job, restart counter is at 2.
[  724.346240] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[  724.378794] studento authd-msentraid.authd-msentraid[4470]: time=2024-12-02T15:40:31.574Z level=ERROR msg="config file has invalid values, did you edit the file \"/var/snap/authd-msentraid/51/broker.conf\"?\nfound invalid character in section \"oidc\", key \"issuer\"\nfound invalid character in section \"oidc\", key \"client_id\""
[  724.379858] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Main process exited, code=exited, status=1/FAILURE
[  724.380060] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Failed with result 'exit-code'.
[  724.587082] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Scheduled restart job, restart counter is at 3.
[  724.596232] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[  724.630418] studento authd-msentraid.authd-msentraid[4498]: time=2024-12-02T15:40:31.826Z level=ERROR msg="config file has invalid values, did you edit the file \"/var/snap/authd-msentraid/51/broker.conf\"?\nfound invalid character in section \"oidc\", key \"issuer\"\nfound invalid character in section \"oidc\", key \"client_id\""
[  724.631555] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Main process exited, code=exited, status=1/FAILURE
[  724.631739] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Failed with result 'exit-code'.
[  724.836992] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Scheduled restart job, restart counter is at 4.
[  724.846270] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[  724.879156] studento authd-msentraid.authd-msentraid[4525]: time=2024-12-02T15:40:32.075Z level=ERROR msg="config file has invalid values, did you edit the file \"/var/snap/authd-msentraid/51/broker.conf\"?\nfound invalid character in section \"oidc\", key \"issuer\"\nfound invalid character in section \"oidc\", key \"client_id\""
[  724.880181] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Main process exited, code=exited, status=1/FAILURE
[  724.880362] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Failed with result 'exit-code'.
[  725.087073] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Scheduled restart job, restart counter is at 5.
[  725.087251] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Start request repeated too quickly.
[  725.087499] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Failed with result 'exit-code'.
[  725.087546] studento systemd[1]: Failed to start snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[  958.103679] studento systemd[1]: Stopping authd.service - Authd daemon service...
[  958.108011] studento systemd[1]: authd.service: Deactivated successfully.
[  958.108117] studento systemd[1]: Stopped authd.service - Authd daemon service.
[  958.119504] studento systemd[1]: Starting authd.service - Authd daemon service...
[  958.146880] studento systemd[1]: Started authd.service - Authd daemon service.
[  997.587251] studento authd[4639]: 2024/12/02 15:45:04 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 1118.076365] studento authd[4639]: 2024/12/02 15:47:05 WARN rpc error: code = NotFound desc = user "USER@DOMAIN" is not known by any broker
[ 1118.143672] studento authd[4639]: 2024/12/02 15:47:05 WARN rpc error: code = NotFound desc =
[ 1118.145679] studento authd[4639]: 2024/12/02 15:47:05 WARN rpc error: code = NotFound desc = user "USER@DOMAIN" is not known by any broker
[ 1289.481859] studento authd[4639]: 2024/12/02 15:49:56 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 1289.545865] studento authd[4639]: 2024/12/02 15:49:56 WARN rpc error: code = NotFound desc =
[ 1289.547792] studento authd[4639]: 2024/12/02 15:49:56 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 1293.768547] studento authd[4639]: 2024/12/02 15:50:00 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 1295.731023] studento authd[4639]: 2024/12/02 15:50:02 WARN rpc error: code = NotFound desc =
[ 1295.732983] studento authd[4639]: 2024/12/02 15:50:02 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 1451.969277] studento systemd[1]: Stopping authd.service - Authd daemon service...
[ 1451.973893] studento systemd[1]: authd.service: Deactivated successfully.
[ 1451.974205] studento systemd[1]: Stopped authd.service - Authd daemon service.
[ 1451.987948] studento systemd[1]: Starting authd.service - Authd daemon service...
[ 1452.014022] studento systemd[1]: Started authd.service - Authd daemon service.
[ 1605.817477] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[ 1629.817808] studento authd[5069]: 2024/12/02 15:55:37 WARN rpc error: code = NotFound desc =
[ 1749.624235] studento authd-msentraid.authd-msentraid[5141]: time=2024-12-02T15:57:36.820Z level=ERROR msg="context canceled"
[ 1749.624754] studento authd[5069]: 2024/12/02 15:57:36 WARN can't check authentication: invalid access authentication key:
[ 1907.913849] studento authd[5069]: 2024/12/02 16:00:15 WARN rpc error: code = NotFound desc =
[ 2295.856082] studento authd[5069]: 2024/12/02 16:06:43 WARN rpc error: code = NotFound desc =
[ 2345.864693] studento authd-msentraid.authd-msentraid[5141]: time=2024-12-02T16:07:33.060Z level=ERROR msg="oauth2: \"invalid_client\" \"AADSTS7000218: The request body must contain the following parameter: 'client_assertion' or 'client_secret'. Trace ID: <UUID redacted> Correlation ID: <UUID redacted> Timestamp: 2024-12-02 16:07:33Z\" \"https://login.microsoftonline.com/error?code=7000218\""
[ 2388.986761] studento authd-msentraid.authd-msentraid[5141]: time=2024-12-02T16:08:16.182Z level=ERROR msg="oauth2: \"invalid_client\" \"AADSTS7000218: The request body must contain the following parameter: 'client_assertion' or 'client_secret'. Trace ID: <UUID redacted> Correlation ID: <UUID redacted> Timestamp: 2024-12-02 16:08:16Z\" \"https://login.microsoftonline.com/error?code=7000218\""
[ 2415.615364] studento authd-msentraid.authd-msentraid[5141]: time=2024-12-02T16:08:42.811Z level=ERROR msg="context canceled"
[ 2415.615927] studento authd[5069]: 2024/12/02 16:08:42 WARN can't check authentication: invalid access authentication key:
[ 2422.347639] studento authd[5069]: 2024/12/02 16:08:49 WARN rpc error: code = NotFound desc =
[ 2463.015405] studento authd-msentraid.authd-msentraid[5141]: time=2024-12-02T16:09:30.211Z level=ERROR msg="oauth2: \"invalid_client\" \"AADSTS7000218: The request body must contain the following parameter: 'client_assertion' or 'client_secret'. Trace ID: <UUID redacted> Correlation ID: <UUID redacted> Timestamp: 2024-12-02 16:09:30Z\" \"https://login.microsoftonline.com/error?code=7000218\""
[ 2860.476364] studento authd[5069]: 2024/12/02 16:16:07 WARN rpc error: code = NotFound desc =
[ 2882.939676] studento authd-msentraid.authd-msentraid[5141]: time=2024-12-02T16:16:30.135Z level=ERROR msg="oauth2: \"invalid_client\" \"AADSTS7000218: The request body must contain the following parameter: 'client_assertion' or 'client_secret'. Trace ID: <UUID redacted> Correlation ID: <UUID redacted> Timestamp: 2024-12-02 16:16:30Z\" \"https://login.microsoftonline.com/error?code=7000218\""
[ 3546.772978] studento systemd[1]: Stopping snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid...
[ 3546.776656] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Deactivated successfully.
[ 3546.776961] studento systemd[1]: Stopped snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[ 3546.803370] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[ 3556.441514] studento systemd[1]: Stopping authd.service - Authd daemon service...
[ 3556.446093] studento systemd[1]: authd.service: Deactivated successfully.
[ 3556.446366] studento systemd[1]: Stopped authd.service - Authd daemon service.
[ 3556.458332] studento systemd[1]: Starting authd.service - Authd daemon service...
[ 3556.484688] studento systemd[1]: Started authd.service - Authd daemon service.
[ 3561.403991] studento authd[5501]: 2024/12/02 16:27:48 WARN rpc error: code = NotFound desc =
[ 3602.077231] studento authd[5501]: 2024/12/02 16:28:29 WARN rpc error: code = NotFound desc =
[ 3611.136226] studento authd[5501]: 2024/12/02 16:28:38 WARN rpc error: code = NotFound desc =
[ 3615.919371] studento authd[5501]: 2024/12/02 16:28:43 WARN rpc error: code = NotFound desc =
[ 3617.979675] studento authd[5501]: 2024/12/02 16:28:45 WARN rpc error: code = NotFound desc =
[ 3629.776740] studento authd[5501]: 2024/12/02 16:28:56 WARN rpc error: code = NotFound desc =
[ 3636.832545] studento authd[5501]: 2024/12/02 16:29:04 WARN rpc error: code = NotFound desc =
[ 3750.248913] studento systemd[1]: Stopping snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid...
[ 3750.255278] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Deactivated successfully.
[ 3750.255553] studento systemd[1]: Stopped snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[ 3750.279805] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[ 3785.299566] studento authd[5501]: 2024/12/02 16:31:32 WARN rpc error: code = NotFound desc =
[ 3791.931400] studento authd[5501]: 2024/12/02 16:31:39 WARN rpc error: code = NotFound desc =
[ 4019.491952] studento authd[5501]: 2024/12/02 16:35:26 WARN rpc error: code = NotFound desc =
[ 4067.888664] studento authd[5501]: 2024/12/02 16:36:15 WARN rpc error: code = NotFound desc =
[ 4159.064993] studento authd[5501]: 2024/12/02 16:37:46 WARN rpc error: code = NotFound desc =
[ 4166.966319] studento authd[5501]: 2024/12/02 16:37:54 WARN rpc error: code = NotFound desc =
[ 4369.721890] studento authd[5501]: 2024/12/02 16:41:16 WARN rpc error: code = NotFound desc =
[ 4410.910240] studento authd[5501]: 2024/12/02 16:41:58 WARN rpc error: code = NotFound desc =
[ 5032.860178] studento authd[5501]: 2024/12/02 16:52:20 WARN rpc error: code = NotFound desc =
[ 5067.049694] studento authd[5501]: 2024/12/02 16:52:54 WARN rpc error: code = NotFound desc =
[ 5070.074428] studento authd[5501]: 2024/12/02 16:52:57 WARN rpc error: code = NotFound desc =
[ 5073.511045] studento authd[5501]: 2024/12/02 16:53:00 WARN rpc error: code = NotFound desc =
[ 5207.188403] studento authd[5501]: 2024/12/02 16:55:14 WARN rpc error: code = NotFound desc =
[ 5210.252050] studento authd-msentraid.authd-msentraid[5628]: time=2024-12-02T16:55:17.448Z level=ERROR msg="could not deserialize token: cipher: message authentication failed"
[ 5214.299152] studento authd-msentraid.authd-msentraid[5628]: time=2024-12-02T16:55:21.495Z level=ERROR msg="could not deserialize token: cipher: message authentication failed"
[ 5215.462743] studento authd-msentraid.authd-msentraid[5628]: time=2024-12-02T16:55:22.658Z level=ERROR msg="could not deserialize token: cipher: message authentication failed"
[ 5215.540634] studento authd[5501]: 2024/12/02 16:55:22 WARN rpc error: code = NotFound desc =
[ 5367.428894] studento authd[5501]: 2024/12/02 16:57:54 WARN rpc error: code = NotFound desc =
[ 5380.156066] studento authd[5501]: 2024/12/02 16:58:07 WARN rpc error: code = NotFound desc =
[ 5395.726454] studento authd[5501]: 2024/12/02 16:58:22 WARN rpc error: code = NotFound desc =
[ 5448.416071] studento authd[5501]: 2024/12/02 16:59:15 WARN rpc error: code = NotFound desc =
[ 6045.595396] studento authd[5501]: 2024/12/02 17:09:12 WARN rpc error: code = NotFound desc =
[ 6076.959230] studento authd[5501]: 2024/12/02 17:09:44 WARN rpc error: code = NotFound desc =
[ 6289.431148] studento authd[5501]: 2024/12/02 17:13:16 WARN rpc error: code = NotFound desc =
[ 6409.216971] studento authd-msentraid.authd-msentraid[5628]: time=2024-12-02T17:15:16.413Z level=ERROR msg="Post \"https://login.microsoftonline.com/<UUID redacted>/oauth2/v2.0/token\": context canceled"
[ 6409.217609] studento authd[5501]: 2024/12/02 17:15:16 WARN can't check authentication: invalid access authentication key:
[ 6585.399775] studento authd[5501]: 2024/12/02 17:18:12 WARN rpc error: code = NotFound desc =
[ 6612.680639] studento authd[5501]: 2024/12/02 17:18:39 WARN rpc error: code = NotFound desc =
[ 6711.299738] studento authd[5501]: 2024/12/02 17:20:18 WARN rpc error: code = NotFound desc =
[ 6716.051248] studento authd[5501]: 2024/12/02 17:20:23 WARN rpc error: code = NotFound desc =
[ 6808.234445] studento authd[5501]: 2024/12/02 17:21:55 WARN rpc error: code = NotFound desc =
[ 6813.232867] studento authd[5501]: 2024/12/02 17:22:00 WARN rpc error: code = NotFound desc =
[ 6902.050215] studento authd[5501]: 2024/12/02 17:23:29 WARN rpc error: code = NotFound desc =
[ 6912.154227] studento authd[5501]: 2024/12/02 17:23:39 WARN rpc error: code = NotFound desc =
[ 6995.566760] studento authd[5501]: 2024/12/02 17:25:02 WARN rpc error: code = NotFound desc =
[ 7000.662472] studento authd[5501]: 2024/12/02 17:25:07 WARN rpc error: code = NotFound desc =
[ 7077.859392] studento authd[5501]: 2024/12/02 17:26:25 WARN rpc error: code = NotFound desc =
[ 7082.887904] studento authd[5501]: 2024/12/02 17:26:30 WARN rpc error: code = NotFound desc =
[ 7108.714113] studento authd[5501]: 2024/12/02 17:26:55 WARN rpc error: code = NotFound desc =
[ 7115.170167] studento authd[5501]: 2024/12/02 17:27:02 WARN rpc error: code = NotFound desc =
[ 7150.647133] studento authd[5501]: 2024/12/02 17:27:37 WARN rpc error: code = NotFound desc =
[ 7157.177696] studento authd[5501]: 2024/12/02 17:27:44 WARN rpc error: code = NotFound desc =
[ 7685.374853] studento systemd[1]: Stopping authd.service - Authd daemon service...
[ 7685.379393] studento systemd[1]: authd.service: Deactivated successfully.
[ 7685.379610] studento systemd[1]: Stopped authd.service - Authd daemon service.
[ 7685.391544] studento systemd[1]: Starting authd.service - Authd daemon service...
[ 7685.411706] studento authd[7018]: INFO Using configuration file: /etc/authd/authd.yaml
[ 7685.411706] studento authd[7018]: DEBUG Verbosity: 2
[ 7685.411706] studento authd[7018]: DEBUG Building authd object
[ 7685.412153] studento authd[7018]: DEBUG Building broker detection
[ 7685.412755] studento authd[7018]: DEBUG Auto-detecting brokers
[ 7685.412853] studento authd[7018]: DEBUG Loading broker from "/etc/authd/brokers.d/msentraid.conf"
[ 7685.412853] studento authd[7018]: DEBUG Dbus broker configuration at "/etc/authd/brokers.d/msentraid.conf"
[ 7685.413027] studento authd[7018]: 2024/12/02 17:36:32 DEBUG Creating user manager with config: {UIDMin:1000000000 UIDMax:1999999999 GIDMin:1000000000 GIDMax:1999999999}
[ 7685.416153] studento authd[7018]: 2024/12/02 17:36:32 DEBUG Cleaning up orphaned user records
[ 7685.418621] studento authd[7018]: 2024/12/02 17:36:32 DEBUG Done cleaning up orphaned user records
[ 7685.418621] studento authd[7018]: DEBUG Building new GRPC NSS service
[ 7685.418621] studento authd[7018]: DEBUG Building new GRPC PAM service
[ 7685.418683] studento authd[7018]: DEBUG Building new daemon
[ 7685.418683] studento authd[7018]: DEBUG Use socket activation
[ 7685.418683] studento authd[7018]: DEBUG Registering GRPC services
[ 7685.418741] studento authd[7018]: DEBUG Starting to serve requests on /run/authd.sock
[ 7685.418792] studento authd[7018]: DEBUG Ready state sent to systemd
[ 7685.418792] studento authd[7018]: INFO Serving GRPC requests on /run/authd.sock
[ 7685.418842] studento systemd[1]: Started authd.service - Authd daemon service.
[ 7694.605253] studento authd[7018]: 2024/12/02 17:36:41 WARN rpc error: code = NotFound desc =
[ 7694.605821] studento authd[7018]: DEBUG User USER is unknown
[ 7695.916975] studento authd[7018]: DEBUG 2102147668-<UUID redacted>: New session for "USER@DOMAIN"
[ 7700.803741] studento authd[7018]: DEBUG 2102147668-<UUID redacted>: Authentication result: granted
[ 7700.804562] studento authd[7018]: DEBUG Updating entry of user "USER@DOMAIN" (UID: 1436533660)
[ 7700.809292] studento authd[7018]: DEBUG 2102147668-<UUID redacted>: End session "Microsoft Entra ID"
[ 7700.853656] studento authd[7018]: 2024/12/02 17:36:48 WARN rpc error: code = NotFound desc =
[ 7770.354217] studento systemd[1]: Stopping authd.service - Authd daemon service...
[ 7770.354611] studento authd[7018]: INFO Stopping daemon requested.
[ 7770.354611] studento authd[7018]: INFO Wait for active requests to close.
[ 7770.354611] studento authd[7018]: DEBUG All connections have now ended.
[ 7770.354946] studento authd[7018]: 2024/12/02 17:37:57 DEBUG Closing grpc manager and cache
[ 7770.358195] studento systemd[1]: authd.service: Deactivated successfully.
[ 7770.358426] studento systemd[1]: Stopped authd.service - Authd daemon service.
[ 7770.374336] studento systemd[1]: Starting authd.service - Authd daemon service...
[ 7770.396247] studento authd[7107]: INFOgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func2() Using configuration file: /etc/authd/authd.yaml
[ 7770.396247] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Verbosity: 3
[ 7770.396630] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building authd object
[ 7770.396630] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building broker detection
[ 7770.397400] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Auto-detecting brokers
[ 7770.397476] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Loading broker from "/etc/authd/brokers.d/msentraid.conf"
[ 7770.397507] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Dbus broker configuration at "/etc/authd/brokers.d/msentraid.conf"
[ 7770.397584] studento authd[7107]: 2024/12/02 17:37:57 DEBUG Creating user manager with config: {UIDMin:1000000000 UIDMax:1999999999 GIDMin:1000000000 GIDMax:1999999999}
[ 7770.400884] studento authd[7107]: 2024/12/02 17:37:57 DEBUG Cleaning up orphaned user records
[ 7770.403185] studento authd[7107]: 2024/12/02 17:37:57 DEBUG Done cleaning up orphaned user records
[ 7770.403226] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building new GRPC NSS service
[ 7770.403226] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building new GRPC PAM service
[ 7770.403226] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building new daemon
[ 7770.403276] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Use socket activation
[ 7770.403276] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Registering GRPC services
[ 7770.403337] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Starting to serve requests on /run/authd.sock
[ 7770.403402] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Ready state sent to systemd
[ 7770.403430] studento authd[7107]: INFOgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func2() Serving GRPC requests on /run/authd.sock
[ 7770.403518] studento systemd[1]: Started authd.service - Authd daemon service.
[ 7820.245018] studento systemd[1]: Stopping snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid...
[ 7820.253191] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Deactivated successfully.
[ 7820.253479] studento systemd[1]: Stopped snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[ 7820.253719] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Consumed 4.140s CPU time, 105.5M memory peak, 0B memory swap peak.
[ 7820.275305] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[ 7820.308335] studento authd-msentraid.authd-msentraid[7205]: time=2024-12-02T17:38:47.504Z level=INFO msg="No configuration file: Config File \"authd-msentraid\" Not Found in \"[/var/snap/authd-msentraid/51 /root/snap/authd-msentraid/51 /etc/authd-msentraid /snap/authd-msentraid/51/bin]\".\nWe will only use the defaults, env variables or flags."
[ 7820.308335] studento authd-msentraid.authd-msentraid[7205]: time=2024-12-02T17:38:47.504Z level=DEBUG msg="Debug mode is enabled"
[ 7820.402794] studento authd-msentraid.authd-msentraid[7205]: time=2024-12-02T17:38:47.598Z level=DEBUG msg="Building new daemon"
[ 7820.402794] studento authd-msentraid.authd-msentraid[7205]: time=2024-12-02T17:38:47.598Z level=DEBUG msg="Starting to serve requests"
[ 7820.402794] studento authd-msentraid.authd-msentraid[7205]: time=2024-12-02T17:38:47.598Z level=INFO msg="Serving requests as com.ubuntu.authd.MSEntraID"
[ 7828.432139] studento authd[7107]: 2024/12/02 17:38:55 WARN rpc error: code = NotFound desc =
[ 7828.432591] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() User "USER@DOMAIN" is unknown
[ 7831.627455] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() 2102147668-<UUID redacted>: New session for "USER@DOMAIN"
[ 7836.047093] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() 2102147668-<UUID redacted>: Authentication result: granted
[ 7836.047508] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Updating entry of user "USER@DOMAIN" (UID: 1436533660)
[ 7836.054435] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() 2102147668-<UUID redacted>: End session "Microsoft Entra ID"
[ 7836.101084] studento authd[7107]: 2024/12/02 17:39:03 WARN rpc error: code = NotFound desc =
[ 8085.262287] studento systemd[1]: Stopping snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid...
[ 8085.262815] studento authd-msentraid.authd-msentraid[7205]: time=2024-12-02T17:43:12.458Z level=INFO msg="Stopping daemon requested."
[ 8085.266210] studento systemd[1]: snap.authd-msentraid.authd-msentraid.service: Deactivated successfully.
[ 8085.266455] studento systemd[1]: Stopped snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[ 8085.294352] studento systemd[1]: Started snap.authd-msentraid.authd-msentraid.service - Service for snap application authd-msentraid.authd-msentraid.
[ 8085.325737] studento authd-msentraid.authd-msentraid[7364]: time=2024-12-02T17:43:12.521Z level=INFO msg="No configuration file: Config File \"authd-msentraid\" Not Found in \"[/var/snap/authd-msentraid/51 /root/snap/authd-msentraid/51 /etc/authd-msentraid /snap/authd-msentraid/51/bin]\".\nWe will only use the defaults, env variables or flags."
[ 8085.325737] studento authd-msentraid.authd-msentraid[7364]: time=2024-12-02T17:43:12.521Z level=DEBUG msg="Debug mode is enabled"
[ 8085.404258] studento systemd[1]: Stopping authd.service - Authd daemon service...
[ 8085.404353] studento authd[7107]: INFOgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func2() Stopping daemon requested.
[ 8085.404353] studento authd[7107]: INFOgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func2() Wait for active requests to close.
[ 8085.404553] studento authd[7107]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() All connections have now ended.
[ 8085.404553] studento authd[7107]: 2024/12/02 17:43:12 DEBUG Closing grpc manager and cache
[ 8085.408064] studento systemd[1]: authd.service: Deactivated successfully.
[ 8085.408336] studento systemd[1]: Stopped authd.service - Authd daemon service.
[ 8085.421549] studento systemd[1]: Starting authd.service - Authd daemon service...
[ 8085.443218] studento authd[7414]: INFOgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func2() Using configuration file: /etc/authd/authd.yaml
[ 8085.443570] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Verbosity: 3
[ 8085.443570] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building authd object
[ 8085.443570] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building broker detection
[ 8085.444504] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Auto-detecting brokers
[ 8085.444577] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Loading broker from "/etc/authd/brokers.d/msentraid.conf"
[ 8085.444600] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Dbus broker configuration at "/etc/authd/brokers.d/msentraid.conf"
[ 8085.444718] studento authd[7414]: 2024/12/02 17:43:12 DEBUG Creating user manager with config: {UIDMin:1000000000 UIDMax:1999999999 GIDMin:1000000000 GIDMax:1999999999}
[ 8085.454687] studento authd[7414]: 2024/12/02 17:43:12 DEBUG Cleaning up orphaned user records
[ 8085.456517] studento authd[7414]: 2024/12/02 17:43:12 DEBUG Done cleaning up orphaned user records
[ 8085.456517] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building new GRPC NSS service
[ 8085.456517] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building new GRPC PAM service
[ 8085.456517] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Building new daemon
[ 8085.456622] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Use socket activation
[ 8085.456622] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Registering GRPC services
[ 8085.456660] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Starting to serve requests on /run/authd.sock
[ 8085.456709] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Ready state sent to systemd
[ 8085.456709] studento authd[7414]: INFOgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func2() Serving GRPC requests on /run/authd.sock
[ 8085.456909] studento systemd[1]: Started authd.service - Authd daemon service.
[ 8085.570802] studento authd-msentraid.authd-msentraid[7364]: time=2024-12-02T17:43:12.766Z level=DEBUG msg="Building new daemon"
[ 8085.570802] studento authd-msentraid.authd-msentraid[7364]: time=2024-12-02T17:43:12.766Z level=DEBUG msg="Starting to serve requests"
[ 8085.570802] studento authd-msentraid.authd-msentraid[7364]: time=2024-12-02T17:43:12.766Z level=INFO msg="Serving requests as com.ubuntu.authd.MSEntraID"
[ 8145.740755] studento authd[7414]: 2024/12/02 17:44:12 WARN rpc error: code = NotFound desc =
[ 8145.741608] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() User "USER@DOMAIN" is unknown
[ 8147.290157] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() 2102147668-<UUID redacted>: New session for "USER@DOMAIN"
[ 8164.610282] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() 2102147668-<UUID redacted>: Authentication result: next
[ 8173.829042] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() 2102147668-<UUID redacted>: Authentication result: granted
[ 8173.829597] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Updating entry of user "USER@DOMAIN" (UID: 1436533660)
[ 8173.838809] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() 2102147668-<UUID redacted>: End session "Microsoft Entra ID"
[ 8173.884691] studento authd[7414]: 2024/12/02 17:44:41 WARN rpc error: code = NotFound desc =
[ 8802.568050] studento authd[7414]: 2024/12/02 17:55:09 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8802.634400] studento authd[7414]: 2024/12/02 17:55:09 WARN rpc error: code = NotFound desc =
[ 8802.634643] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() User "USER" is unknown
[ 8802.636569] studento authd[7414]: 2024/12/02 17:55:09 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8809.350290] studento authd[7414]: 2024/12/02 17:55:16 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8811.391963] studento authd[7414]: 2024/12/02 17:55:18 WARN rpc error: code = NotFound desc =
[ 8811.392321] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() User "USER" is unknown
[ 8811.394192] studento authd[7414]: 2024/12/02 17:55:18 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8814.947808] studento authd[7414]: 2024/12/02 17:55:22 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8816.556133] studento authd[7414]: 2024/12/02 17:55:23 WARN rpc error: code = NotFound desc =
[ 8816.556458] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() User "USER" is unknown
[ 8816.558978] studento authd[7414]: 2024/12/02 17:55:23 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8839.480436] studento authd[7414]: 2024/12/02 17:55:46 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8839.548801] studento authd[7414]: 2024/12/02 17:55:46 WARN rpc error: code = NotFound desc =
[ 8839.548989] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() User "USER" is unknown
[ 8839.551039] studento authd[7414]: 2024/12/02 17:55:46 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8841.034439] studento authd[7414]: 2024/12/02 17:55:48 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8842.798586] studento authd[7414]: 2024/12/02 17:55:49 WARN rpc error: code = NotFound desc =
[ 8842.798909] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() User "USER" is unknown
[ 8842.800572] studento authd[7414]: 2024/12/02 17:55:49 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8845.091579] studento authd[7414]: 2024/12/02 17:55:52 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker
[ 8846.606489] studento authd[7414]: 2024/12/02 17:55:53 WARN rpc error: code = NotFound desc =
[ 8846.606823] studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() User "USER" is unknown
[ 8846.608631] studento authd[7414]: 2024/12/02 17:55:53 WARN rpc error: code = NotFound desc = user "USER" is not known by any broker

authd broker configuration

/etc/authd/brokers.d/msentraid.conf

# This section is used by authd to identify and communicate with the broker.
# It should not be edited.
[authd]
name = Microsoft Entra ID
brand_icon = /snap/authd-msentraid/current/broker_icon.png
dbus_name = com.ubuntu.authd.MSEntraID
dbus_object = /com/ubuntu/authd/MSEntraID

authd-msentraid configuration

[oidc]
#issuer = https://login.microsoftonline.com/<UUID redacted>/v2.0
#client_id = <UUID redacted>
issuer = https://login.microsoftonline.com/<UUID redacted>/v2.0
client_id = <UUID redacted>

[users]
# The directory where the home directory will be created for new users.
# Existing users will keep their current directory.
# The user home directory will be created in the format of {home_base_dir}/{username}
home_base_dir = /home

# The username suffixes that are allowed to login via ssh without existing previously in the system.
# The suffixes must be separated by commas.
ssh_allowed_suffixes = @DOMAIN

Double check your logs

adombeck commented 1 day ago

That's weird. I don't see anything out of the ordinary in the logs you provided. Is anything printed to the terminal when the SSH connection is disconnected? Please also check if the journal on the server shows any relevant messages (for example by running journalctl -f on the server before you try to connect via SSH with the Microsoft Entra user).

RandyParedis commented 1 day ago

Thank you for helping!

On the client side (from WSL), all I get is:

$> ssh USER@DOMAIN@SERVER_IP
MY VERY FUNNY BANNER TEXT HERE
== Broker selection ==
1 - local
2 - Microsoft Entra ID
Select broker: 2
Insert 'r' to cancel the request and go back
Enter your local password:
Connection closed by SERVER_IP port 22

When I run journalctl -f, I get:

Dec 03 09:24:58 studento authd[7414]: 2024/12/03 09:24:58 WARN rpc error: code = NotFound desc =
Dec 03 09:24:58 studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() User "USER@DOMAIN" is unknown
Dec 03 09:25:00 studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() <REDACTED>: New session for "USER@DOMAIN"
Dec 03 09:25:01 studento CRON[11235]: pam_unix(cron:session): session opened for user root(uid=0) by root(uid=0)
Dec 03 09:25:01 studento CRON[11249]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Dec 03 09:25:01 studento CRON[11235]: pam_unix(cron:session): session closed for user root
Dec 03 09:25:06 studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() <REDACTED>: Authentication result: granted
Dec 03 09:25:06 studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() Updating entry of user "USER@DOMAIN" (UID: 1436533660)
Dec 03 09:25:06 studento authd[7414]: DEBUGgithub.com/ubuntu/authd/internal/log/log.go:53 github.com/ubuntu/authd/internal/log.init.logFuncAdapter.func1() <REDACTED>: End session "Microsoft Entra ID"
Dec 03 09:25:06 studento authd[7414]: 2024/12/03 09:25:06 WARN rpc error: code = NotFound desc =
Dec 03 09:25:06 studento unix_chkpwd[11251]: could not obtain user info (USER@DOMAIN)
Dec 03 09:25:06 studento kernel: audit: type=1400 audit(1733217906.084:207): apparmor="DENIED" operation="connect" class="file" profile="unix-chkpwd" name="/run/authd.sock" pid=11251 comm="unix_chkpwd" requested_mask="wr" denied_mask="wr" fsuid=0 ouid=0
Dec 03 09:25:06 studento sshd[11217]: error: PAM: User account has expired for USER@DOMAIN from CLIENT_IP
Dec 03 09:25:06 studento sshd[11217]: fatal: monitor_read: unpermitted request 104

The same happens after clearing the cache with: sudo rm -rf /var/cache/authd/ && sudo rm -r /var/snap/authd-msentraid/current/cache && sudo snap restart authd-msentraid && sudo systemctl restart authd

Is this an issue in the PAM perhaps? After talking to the team, it turns out someone tried to setup LDAP first through SSSD, but the service is disabled and turned off through pam-auth-update, so I don't think this should impact anything.

adombeck commented 1 day ago

Yes, looks like PAM is incorrectly configured. Please paste the output of:

for f in /etc/pam.d/gdm-authd /etc/pam.d/common-auth /etc/pam.d/common-account /etc/pam.d/common-password; do
echo "#### $f\n\`\`\`"
cat "$f"
echo \`\`\`
done
3v1n0 commented 1 day ago

Other log that can help to see what's happening in PAM is /var/log/auth.log.

Also installing pamtester you could get more info on what's the final error by using pamtester sshd foo@domain.com authenticate, you can't see what each module returned without their own logging though (or without enabling pam debug at compile time).

RandyParedis commented 23 hours ago

My PAM config is as follows:

/etc/pam.d/gdm-authd

#%PAM-1.0
auth    [success=ok user_unknown=ignore default=bad] pam_succeed_if.so user != root quiet_success
auth    [success=1 ignore=ignore default=die] pam_authd.so
# If authd ignored the request => local broker is selected,
# then we continue with normal stack
auth    substack        common-auth

auth    requisite       pam_nologin.so
auth    optional        pam_gnome_keyring.so

account [default=ignore success=ok user_unknown=ignore] pam_authd.so
# This is potentially loading pam_authd.again but we've checks in AcctMgmt() to
# prevent this to happen when the gdm-authd service is used without GDM extensions.
# Plus the model used by the services is different, so there's no risk for this to happen.
@include common-account

# SELinux needs to be the first session rule. This ensures that any
# lingering context has been cleared. Without this it is possible
# that a module could execute code in the wrong domain.
session [success=ok ignore=ignore module_unknown=ignore default=bad]        pam_selinux.so close
session required        pam_loginuid.so
# SELinux needs to intervene at login time to ensure that the process
# starts in the proper default security context. Only sessions which are
# intended to run in the user's context should be run after this.
# pam_selinux.so changes the SELinux context of the used TTY and configures
# SELinux in order to transition to the user context with the next execve()
# call.
session [success=ok ignore=ignore module_unknown=ignore default=bad]        pam_selinux.so open
session optional        pam_keyinit.so force revoke
session required        pam_limits.so
session required        pam_env.so readenv=1
session required        pam_env.so readenv=1 envfile=/etc/default/locale
@include common-session
session optional        pam_mkhomedir.so
session optional        pam_gnome_keyring.so auto_start
@include common-password

/etc/pam.d/common-auth

#
# /etc/pam.d/common-auth - authentication settings common to all services
#
# This file is included from other service-specific PAM config files,
# and should contain a list of the authentication modules that define
# the central authentication scheme for use on the system
# (e.g., /etc/shadow, LDAP, Kerberos, etc.).  The default is to use the
# traditional Unix authentication mechanisms.
#
# As of pam 1.0.1-6, this file is managed by pam-auth-update by default.
# To take advantage of this, it is recommended that you configure any
# local modules either before or after the default block, and use
# pam-auth-update to manage selection of other modules.  See
# pam-auth-update(8) for details.

# here are the per-package modules (the "Primary" block)
auth    [success=2 ignore=ignore default=die]   pam_authd_exec.so /usr/libexec/authd-pam
auth    [success=1 default=ignore]      pam_unix.so nullok try_first_pass
# here's the fallback if no module succeeds
auth    requisite                       pam_deny.so
# prime the stack with a positive return value if there isn't one already;
# this avoids us returning an error just because nothing sets a success code
# since the modules above will each just jump around
auth    required                        pam_permit.so
# and here are more per-package modules (the "Additional" block)
auth    optional                        pam_cap.so
# end of pam-auth-update config

/etc/pam.d/common-account

#
# /etc/pam.d/common-account - authorization settings common to all services
#
# This file is included from other service-specific PAM config files,
# and should contain a list of the authorization modules that define
# the central access policy for use on the system.  The default is to
# only deny service to users whose accounts are expired in /etc/shadow.
#
# As of pam 1.0.1-6, this file is managed by pam-auth-update by default.
# To take advantage of this, it is recommended that you configure any
# local modules either before or after the default block, and use
# pam-auth-update to manage selection of other modules.  See
# pam-auth-update(8) for details.
#

# here are the per-package modules (the "Primary" block)
account [success=1 new_authtok_reqd=done default=ignore]        pam_unix.so
# here's the fallback if no module succeeds
account requisite                       pam_deny.so
# prime the stack with a positive return value if there isn't one already;
# this avoids us returning an error just because nothing sets a success code
# since the modules above will each just jump around
account required                        pam_permit.so
# and here are more per-package modules (the "Additional" block)
account [default=ignore success=ok user_unknown=ignore] pam_authd_exec.so /usr/libexec/authd-pam
# end of pam-auth-update config

/etc/pam.d/common-password

#
# /etc/pam.d/common-password - password-related modules common to all services
#
# This file is included from other service-specific PAM config files,
# and should contain a list of modules that define the services to be
# used to change user passwords.  The default is pam_unix.

# Explanation of pam_unix options:
# The "yescrypt" option enables
#hashed passwords using the yescrypt algorithm, introduced in Debian
#11.  Without this option, the default is Unix crypt.  Prior releases
#used the option "sha512"; if a shadow password hash will be shared
#between Debian 11 and older releases replace "yescrypt" with "sha512"
#for compatibility .  The "obscure" option replaces the old
#`OBSCURE_CHECKS_ENAB' option in login.defs.  See the pam_unix manpage
#for other options.

# As of pam 1.0.1-6, this file is managed by pam-auth-update by default.
# To take advantage of this, it is recommended that you configure any
# local modules either before or after the default block, and use
# pam-auth-update to manage selection of other modules.  See
# pam-auth-update(8) for details.

# here are the per-package modules (the "Primary" block)
password        [success=3 ignore=ignore default=die]   pam_authd_exec.so /usr/libexec/authd-pam
password        requisite                       pam_pwquality.so retry=3
password        [success=1 default=ignore]      pam_unix.so obscure use_authtok try_first_pass yescrypt
# here's the fallback if no module succeeds
password        requisite                       pam_deny.so
# prime the stack with a positive return value if there isn't one already;
# this avoids us returning an error just because nothing sets a success code
# since the modules above will each just jump around
password        required                        pam_permit.so
# and here are more per-package modules (the "Additional" block)
# end of pam-auth-update config

In my /var/log/auth.log, I have:

2024-12-03T12:35:01.667149+00:00 studento CRON[12025]: pam_unix(cron:session): session opened for user root(uid=0) by root(uid=0)
2024-12-03T12:35:01.672458+00:00 studento CRON[12025]: pam_unix(cron:session): session closed for user root
2024-12-03T12:36:39.262712+00:00 studento unix_chkpwd[12068]: could not obtain user info (USER@DOMAIN)
2024-12-03T12:36:39.263289+00:00 studento sshd[12050]: error: PAM: User account has expired for USER@DOMAIN from CLIENT_IP
2024-12-03T12:36:39.299408+00:00 studento sshd[12050]: fatal: monitor_read: unpermitted request 104

The pamtester command just resulted in Authentication failure. Surprisingly, this time I got a QR code in the terminal, which does not show through ssh..

3v1n0 commented 22 hours ago

Surprisingly, this time I got a QR code in the terminal, which does not show through ssh..

Yeah, that's expected: Sadly we can't reliably support qr codes through SSH as most of clients don't support it (see #497 and #500), so depending on the UI we may show it or not for now.

We've plans for using an #-rendered version in SSH in future, but that has not yet been defined.

RandyParedis commented 22 hours ago

Surprisingly, this time I got a QR code in the terminal, which does not show through ssh..

Yeah, that's expected: Sadly we can't reliably support qr codes through SSH as most of clients don't support it (see #497 and #500), so depending on the UI we may show it or not for now.

We've plans for using an #-rendered version in SSH in future, but that has not yet been defined.

Ah, I see. Thanks! I just found it curious that I suddenly saw it. Not sure what differs between SSH and pamtester; but I assume it has to do with UTF-8 or something... Either way, that is a different topic.

3v1n0 commented 22 hours ago
Dec 03 09:25:06 studento unix_chkpwd[11251]: could not obtain user info (USER@DOMAIN)
Dec 03 09:25:06 studento kernel: audit: type=1400 audit(1733217906.084:207): apparmor="DENIED" operation="connect" class="file" profile="unix-chkpwd" name="/run/authd.sock" pid=11251 comm="unix_chkpwd" requested_mask="wr" denied_mask="wr" fsuid=0 ouid=0

So this is due to apparmor blocking access to authd socket when doing getpwnames from NSS module, this is likely an issue to consider for other cases, but still it's not the bug here. Since the fact it fails it can't lead to the authentication to fail.

Now, looking at your pam configurations, /etc/pam.d/common-account seems to have authd in the wrong place, what if it would be:

#
# /etc/pam.d/common-account - authorization settings common to all services
#
# This file is included from other service-specific PAM config files,
# and should contain a list of the authorization modules that define
# the central access policy for use on the system.  The default is to
# only deny service to users whose accounts are expired in /etc/shadow.
#
# As of pam 1.0.1-6, this file is managed by pam-auth-update by default.
# To take advantage of this, it is recommended that you configure any
# local modules either before or after the default block, and use
# pam-auth-update to manage selection of other modules.  See
# pam-auth-update(8) for details.
#

# here are the per-package modules (the "Primary" block)
account [success=2 ignore=ignore default=die]   pam_authd_exec.so /usr/libexec/authd-pam
account [success=1 new_authtok_reqd=done default=ignore]        pam_unix.so
# here's the fallback if no module succeeds
account requisite                       pam_deny.so
# prime the stack with a positive return value if there isn't one already;
# this avoids us returning an error just because nothing sets a success code
# since the modules above will each just jump around
account required                        pam_permit.so
# end of pam-auth-update config

As per the pamtester before, I've updated the comment to make clear that you should use an actual user name there and not mine :smile:. So test that again with pamtester sshd user@domain.bar acct_mgmt (after ensuring that using authenticate works too).

3v1n0 commented 21 hours ago

If that works, go back to the default (by restoring the file or purging authd and installing it again), then modify /usr/share/pam-configs/authd so that (ignore the paths, only the changed lines):

diff --git a/debian/pam-configs/authd.in b/debian/pam-configs/authd.in
index 15528e92..808bbbda 100644
--- a/debian/pam-configs/authd.in
+++ b/debian/pam-configs/authd.in
@@ -5,7 +5,7 @@ Priority: 1050
 Auth-Type: Primary
 Auth:
    [success=end ignore=ignore default=die] pam_authd_exec.so @AUTHD_DAEMONS_PATH@/authd-pam
-Account-Type: Additional
+Account-Type: Primary
 Account:
    [default=ignore success=ok user_unknown=ignore] pam_authd_exec.so @AUTHD_DAEMONS_PATH@/authd-pam
 Password-Type: Primary

And run pam-auth-update --disable authd and enable it again pam-auth-update --enable authd (or just run pam-auth-update to rely on its UI to toggle it).

RandyParedis commented 21 hours ago

As per the pamtester before, I've updated the comment to make clear that you should use an actual user name there and not mine 😄. So test that again with pamtester sshd user@domain.bar acct_mgmt (after ensuring that using authenticate works too).

I figured :) ; but I forgot about the domain in my earlier tests... When I run the right command, I get:

#> pamtester sshd USER@DOMAIN authenticate
Enter your local password
pamtester: successfully authenticated
#> pamtester sshd USER@DOMAIN acct_mgmt
pamtester: Authentication failure

This happens both for the original file, and when I change the line in the file you shared. Changing the Account-Type in pam-configs/authd is no different.

I have reverted all these changes just to be sure.

3v1n0 commented 19 hours ago

This happens both for the original file, and when I change the line in the file you shared. Changing the Account-Type in pam-configs/authd is no different.

Do you get the same with actual ssh authentication too?

As pam tester may still fail because of other reasons.

RandyParedis commented 1 hour ago

I get the following error when using SSH (after changing /etc/pam.d/common-account):

Can't set default broker ("2102147668") for "USER@DOMAIN": can't set default broker "2102147668" for user "USER@DOMAIN": no result matching USER@DOMAIN in UserByName