aad-auth icon indicating copy to clipboard operation
aad-auth copied to clipboard
verified publisher icon ubuntu

Login fails

Open turowicz opened this issue 2 years ago • 5 comments

Is there an existing issue for this?

  • [X] I have searched the existing issues and found none that matched mine

Describe the issue

I have installed libpam-aad and libnss-aad and configured the app_id and tenant_id in aad.conf, but the login doesn't work.

Steps to reproduce it

  1. Go to Ubuntu login
  2. Enter azure ad login (lowercase)
  3. Enter password
  4. Login failed

Ubuntu users: System information and logs

libnss_report.txt libpam_report.txt

Non Ubuntu users: System information and logs

Environment

  • aad-auth version: 0.5.2
  • Distribution: Ubuntu
  • Distribution version: 23.10

Log files

Please redact/remove sensitive information:

Dec 19 16:18:30 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): aad auth debug enabled
Dec 19 16:18:30 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): PAM AAD DEBUG enabled
Dec 19 16:18:30 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): Loading configuration from /etc/aad.conf
Dec 19 16:18:30 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): Connecting to "https://login.microsoftonline.com/7dc146bd-2748-4f55-a91b-6959e70f2a90", with clientID "c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663" for user "[email protected]"
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): Authentication successful even if requiring MFA
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): Cache initialization
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): Opening cache in /var/lib/aad/cache
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): check file permissions on /var/lib/aad/cache/shadow.db
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): check file permissions on /var/lib/aad/cache/passwd.db
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): Shadow db mode: 2
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): Cleaning up db. Removing entries that last authenticated online more than 180 days ago
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): getting user information from cache for "[email protected]"
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): encrypt password for user "[email protected]"
Dec 19 16:18:33 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): updating from last online login information for user "[email protected]"
Dec 19 16:18:34 surveily-wt-04 gdm-password][26054]: pam_aad(gdm-password:auth): Close database request

Application settings

Please redact/remove sensitive information:

tenant_id = 7dc146bd-2748-4f55-a91b-6959e70f2a90
app_id = c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663

Relevant information

I install the pam and nss libraries from apt.

Double check your logs

  • [X] I have redacted any sensitive information from the logs

turowicz avatar Dec 19 '23 15:12 turowicz

cc @GabrielNagy @jibel

turowicz avatar Dec 20 '23 08:12 turowicz 

2023-12-19T16:18:30.564395+01:00 surveily-wt-04 gdm-password]: pam_unix(gdm-password:auth): authentication failure; logname= uid=0 euid=0 tty=/dev/tty1 ruser= rhost=  [email protected]
2023-12-19T16:18:30.600908+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): Connecting to "https://login.microsoftonline.com/7dc146bd-2748-4f55-a91b-6959e70f2a90", with clientID "c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663" for user "[email protected]"
2023-12-19T16:18:33.481626+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): getting user information from cache for "[email protected]"
2023-12-19T16:18:33.481800+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): encrypt password for user "[email protected]"
2023-12-19T16:18:33.531897+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): updating from last online login information for user "[email protected]"
2023-12-20T09:10:40.228948+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): Connecting to "https://login.microsoftonline.com/7dc146bd-2748-4f55-a91b-6959e70f2a90", with clientID "c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663" for user "[email protected]"
2023-12-20T09:10:43.319456+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): Connecting to "https://login.microsoftonline.com/7dc146bd-2748-4f55-a91b-6959e70f2a90", with clientID "c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663" for user "[email protected]"
2023-12-20T09:11:09.685972+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): Connecting to "https://login.microsoftonline.com/7dc146bd-2748-4f55-a91b-6959e70f2a90", with clientID "c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663" for user "[email protected]"
2023-12-20T09:11:10.087521+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): getting user information from cache for "[email protected]"
2023-12-20T09:11:10.087642+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): generate user id for user "[email protected]"
2023-12-20T09:11:10.087745+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): user id for "[email protected]" is 2794555040
2023-12-20T09:11:10.087871+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): Getting home directory for [email protected]
2023-12-20T09:11:10.087954+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): inserting in cache user "[email protected]"
2023-12-20T09:11:10.094460+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): encrypt password for user "[email protected]"
2023-12-20T09:11:10.143655+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): updating from last online login information for user "[email protected]"
2023-12-20T09:36:34.956574+01:00 surveily-wt-04 gdm-password]: pam_unix(gdm-password:auth): authentication failure; logname= uid=0 euid=0 tty=/dev/tty1 ruser= rhost=  [email protected]
2023-12-20T09:36:34.957750+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): Connecting to "https://login.microsoftonline.com/7dc146bd-2748-4f55-a91b-6959e70f2a90", with clientID "c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663" for user "[email protected]"
2023-12-20T09:36:35.434113+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): getting user information from cache for "[email protected]"
2023-12-20T09:36:35.434218+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): encrypt password for user "[email protected]"
2023-12-20T09:36:35.483019+01:00 surveily-wt-04 gdm-password]: pam_aad(gdm-password:auth): updating from last online login information for user "[email protected]"

turowicz avatar Dec 20 '23 08:12 turowicz

This test URL gives me right credentials:

https://login.microsoftonline.com/7dc146bd-2748-4f55-a91b-6959e70f2a90/oauth2/v2.0/authorize?client_id=c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663&nonce=defaultNonce&redirect_uri=https%3A%2F%2Fjwt.ms&scope=openid+profile+User.read&response_type=id_token

{
  "typ": "JWT",
  "alg": "RS256",
  "kid": "T1St-dLTvyWRgxB_676u8krXS-I"
}.{
  "aud": "c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663",
  "iss": "https://login.microsoftonline.com/7dc146bd-2748-4f55-a91b-6959e70f2a90/v2.0",
  "iat": 1703066461,
  "nbf": 1703066461,
  "exp": 1703070361,
  "aio": "AWQAm/8VAAAAB7eWpjyQj0Pr2G781ukBTUcovHnf25QAmZ4OpEwXEFQkgCuWju7JMqkU8GSPqQGSreXR6ItizDmpzw4KIo+XJMadckLQN7vboiRAnXxt+ND7pBbb4QLJJm7EdR8BMyA5",
  "cc": "CgEAEgxzdXJ2ZWlseS5jb20aEgoQXDmCxtJlZEejgD5JScfvtSISChAb+SjKTCV4RbTy9rt0CnkAMgJFVTgA",
  "family_name": "Turowicz",
  "given_name": "Wojciech",
  "name": "Wojciech Turowicz",
  "nonce": "defaultNonce",
  "oid": "467f62a3-d65f-4a00-8031-7e5c3f40e02d",
  "preferred_username": "[email protected]",
  "rh": "0.ATwAvUbBfUgnVU-pG2lZ5w8qkA_c5McMni1LnMg8CLf9JmM8AKM.",
  "sub": "S-ZgY3BfsM5YyyJeT-TPoC3Ont4gya6S_N8Poebjadc",
  "tid": "7dc146bd-2748-4f55-a91b-6959e70f2a90",
  "uti": "G_koykwleEW08va7dAp5AA",
  "ver": "2.0"
}.[Signature]

turowicz avatar Dec 20 '23 10:12 turowicz 

Dec 20 11:40:27 surveily-wt-04 aad_auth[53266]: nss_aad: Log output set to syslog
Dec 20 11:40:27 surveily-wt-04 aad_auth[53266]: nss_aad: Log level set to Debug
Dec 20 11:40:27 surveily-wt-04 aad_auth[53266]: nss_aad: get_all_entries for group
Dec 20 11:40:27 surveily-wt-04 aad_auth[53266]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:40:27 surveily-wt-04 aad_auth[53266]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:40:27 surveily-wt-04 aad_auth[53266]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:40:27 surveily-wt-04 aad_auth[53266]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }
Dec 20 11:40:30 surveily-wt-04 aad_auth[53464]: nss_aad: Log output set to syslog
Dec 20 11:40:30 surveily-wt-04 aad_auth[53464]: nss_aad: Log level set to Debug
Dec 20 11:40:30 surveily-wt-04 aad_auth[53464]: nss_aad: get_all_entries for group
Dec 20 11:40:30 surveily-wt-04 aad_auth[53464]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:40:30 surveily-wt-04 aad_auth[53464]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:40:30 surveily-wt-04 aad_auth[53464]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:40:30 surveily-wt-04 aad_auth[53464]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: Log output set to syslog
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: Log level set to Debug
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: get_all_entries for group
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: get_all_entries for group
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:40:30 surveily-wt-04 aad_auth[53478]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }
Dec 20 11:41:03 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): aad auth debug enabled
Dec 20 11:41:03 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): PAM AAD DEBUG enabled
Dec 20 11:41:03 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): Loading configuration from /etc/aad.conf
Dec 20 11:41:03 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): Connecting to "https://login.microsoftonline.com/7dc146bd-2748-4f55-a91b-6959e70f2a90", with clientID "c7e4dc0f-9e0c-4b2d-9cc8-3c08b7fd2663" for user "[email protected]"
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): Authentication successful even if requiring MFA
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): Cache initialization
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): Opening cache in /var/lib/aad/cache
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): check file permissions on /var/lib/aad/cache/passwd.db
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): check file permissions on /var/lib/aad/cache/shadow.db
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): Shadow db mode: 2
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): Cleaning up db. Removing entries that last authenticated online more than 180 days ago
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): getting user information from cache for "[email protected]"
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): encrypt password for user "[email protected]"
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): updating from last online login information for user "[email protected]"
Dec 20 11:41:04 surveily-wt-04 gdm-password][53881]: pam_aad(gdm-password:auth): Close database request
Dec 20 11:41:14 surveily-wt-04 aad_auth[54107]: nss_aad: Log output set to syslog
Dec 20 11:41:14 surveily-wt-04 aad_auth[54107]: nss_aad: Log level set to Debug
Dec 20 11:41:14 surveily-wt-04 aad_auth[54107]: nss_aad: get_entry_by_name for passwd for name: pam_unix_non_existent:
Dec 20 11:41:14 surveily-wt-04 aad_auth[54107]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:41:14 surveily-wt-04 aad_auth[54107]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:41:14 surveily-wt-04 aad_auth[54107]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:41:14 surveily-wt-04 aad_auth[54107]: nss_aad: no record found
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: get_all_entries for group
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: get_all_entries for group
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: get_all_entries for group
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:41:17 surveily-wt-04 aad_auth[54107]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: Log output set to syslog
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: Log level set to Debug
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: get_all_entries for group
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: get_entry_by_name for passwd for name: pam_unix_non_existent:
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:41:36 surveily-wt-04 aad_auth[54673]: nss_aad: no record found
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: get_all_entries for group
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: get_all_entries for group
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: opening database connection from /var/lib/aad/cache
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: Checking file "/var/lib/aad/cache/passwd.db" permissions
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: Checking file "/var/lib/aad/cache/shadow.db" permissions
Dec 20 11:41:38 surveily-wt-04 aad_auth[54673]: nss_aad: found record: Group { name: "[email protected]", passwd: "x", gid: 2794555040, members: ["[email protected]"] }

turowicz avatar Dec 20 '23 10:12 turowicz

This computer has been previously joined to a regular Active Directory with sssd. Perhaps that is the issue? I have uninstalled sssd-ad sssd-tools realmd adcli krb5-user but maybe there are some leftovers?

turowicz avatar Dec 20 '23 11:12 turowicz