search

jhrozek / pam_hbac

A simple pam account module to process HBAC rules stored on an IPA server
GNU General Public License v3.0
10 stars 9 forks source link

Rule evaluation for AD users not matching, possible issue using "domain resolution order" in IPA 4.5.0 #102

Open nazunalika opened 7 years ago

nazunalika commented 7 years ago

I've seem to run into a rather interesting issue. The pam_hbac module doesn't seem to want to evaluate my rules when I'm using domain resolution order on ipa 4.5.0, and I have a hunch that it might be because with that set, multiple UID entries appear and the groups in which I am a member of only show user@domain.tld rather than just "user". I can imagine this would throw off the intent of what this module does.

This is what I tried:

In both cases, I put account required pam_hbac.so right after pam_sss or pam_ldap. Both don't seem to want to work. I considered on trying to find the sssd 1.9 copr repo for RHEL 5 to see if I could have potentially better success, but I don't think I would, unless you believe I should try that.

Here's my id/getent outputs:

[louis.abel@devteamsite2 ~]$ id
uid=10000(louis.abel) gid=1006800013(aocusers) groups=1006800013(aocusers) context=root:system_r:unconfined_t:SystemLow-SystemHigh

$ getent group unixadm
unixadm:*:5901:louis.abel@ad.example.com

Using sssd:

Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): Rule All_UNIX is enabled
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): Found 1 members
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): unixadm is a group member object
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): Setting category ALL for service
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): Found 0 members
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): Setting category ALL for host
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): Found 0 members
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): ph_get_hbac_rules: OK
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): [< hbac_evaluate()
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):       REQUEST:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               service [sshd]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               service_group:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):                       [default_login_services]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):                       [default_login_services_all]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):                       [default_login_services_legacy]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               user [louis.abel]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               user_group:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):                       [aocusers]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               targethost [devteamsite2.example.com]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               targethost_group:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):                       [legacy]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):       srchost (none)
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               request time 2017-10-05 00:49:12
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):       RULE [All_UNIX] [ENABLED]:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):       services:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               category [0x1] [ALL]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               services_names (none)
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               services_groups (none)
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):       users:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               category [0] [NONE]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               users_names (none)
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               users_groups:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):                       [unixadm]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):       targethosts:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               category [0x1] [ALL]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               targethosts_names (none)
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               targethosts_groups (none)
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):       srchosts:
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               category [0x1] [ALL]
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               srchosts_names (none)
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account):               srchosts_groups (none)
Oct  5 00:49:13 devteamsite2 sshd[24206]: pam_hbac(sshd:account): The rule [All_UNIX] did not match.

Using nss-pam-ldapd (note I tried both with a domain and without a domain on my username). Either way when I use id or I su into the account, it shows user@domain@server.

Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): debug option found
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): config file: /etc/pam_hbac.conf
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): URI: ldap://np-ipa01.ipa.example.com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): search base: dc=ipa,dc=example,dc=com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): bind dn: uid=hbac,cn=sysaccounts,cn=etc,dc=ipa,dc=example,dc=com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): ph_init: OK
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): URI: ldap://np-ipa01.ipa.example.com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): search base: dc=ipa,dc=example,dc=com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): bind DN: uid=hbac,cn=sysaccounts,cn=etc,dc=ipa,dc=example,dc=com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): client hostname: devteamsite2.example.com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): cert: not set
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): timeout 5
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): START TLS result: Success(0), Start TLS request accepted.Server willing to negotiate SSL.
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): ph_connect: OK
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): Service: sshd
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): User: louis.abel@ad.example.com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): Tty: ssh
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): Ruser: (not available)
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): Rhost: localhost.localdomain
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): Cannot find user louis.abel@ad.example.com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): Did not find user louis.abel@ad.example.com
Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): returning [10]: User not known to the underlying authentication module
nazunalika commented 7 years ago

While I can't get the debug logs similar to this from Solaris 11, it seems to be causing core dumps. I know when I undo the domain resolution order, none of this occurs below. 

Oct  6 12:13:36 devu16 genunix: [ID 603404 kern.notice] NOTICE: core_log: su[7281] core dumped: /var/cores/core.su.7281
Oct  6 12:19:59 devu16 genunix: [ID 603404 kern.notice] NOTICE: core_log: sshd[7346] core dumped: /var/cores/core.sshd.7346

I'm not sure if this is related - it might be. Because I know this causes the same situation.

root@devu16:~# su - louis.abel
Assertion failed: strcasecmp(user_name, pwd.pw_name) == 0, file ../common/setproject.c, line 1809, function proj_check_user
Abort (core dumped)

Which I do have an open case with Oracle to fix this (expected fix October 20). I'm going to assume this is somewhat unrelated, but I'll leave it here just in case.

jhrozek commented 6 years ago

First, I'm very sorry I forgot about this issue.

I can add more debug statements to the code to see what exactly is going on, but these lines:

Oct  5 01:02:34 devteamsite2 sshd[24549]: pam_hbac(sshd:account): Cannot find user louis.abel@ad.example.com

Just say that pam_hbac called getpwnam(louis.abel@ad.example.com) which did not return anything.

Does also "getent passwd louis.abel@ad.example.com" work from the command line?

If you run pam_hbac, do you see in the IPA DS logs LDAP queries (from nss-pam-ldapd) that would make sense and would find the user?

nazunalika commented 6 years ago 
[root@qadesftp ~]# getent passwd louis.abel
louis.abel@ad.example.com:*:10000:1006800013:Louis Abel:/home/louis.abel:/bin/bash
[root@qadesftp ~]# getent passwd louis.abel@ad.example.com
louis.abel@ad.example.com:*:10000:1006800013:Louis Abel:/home/louis.abel:/bin/bash

It's odd that it doesn't return anything since getent seems to work here. As for DS logs...

I don't see anything that's making sense to me immediately. I would've expected some specific searches for HBAC.

[20/Nov/2017:12:20:24.744146523 +0000] conn=17292638 op=2 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(uid=louis.abel)" attrs=ALL
[20/Nov/2017:12:20:24.748473967 +0000] conn=17292638 op=3 BIND dn="uid=louis.abel,cn=users,cn=compat,dc=ipa,dc=example,dc=com" method=128 version=3
[20/Nov/2017:12:20:24.755229228 +0000] conn=17279184 op=67 SRCH base="cn=Default Trust View,cn=views,cn=accounts,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=ipaUserOverride)(uid=louis.abel))" attrs=ALL
[20/Nov/2017:12:20:25.201007509 +0000] conn=17279184 op=76 SRCH base="cn=hbac,dc=ipa,dc=example,dc=com" scope=2 filter="(objectClass=ipaHBACService)" attrs="objectClass cn ipaUniqueID member memberOf"
[20/Nov/2017:12:20:25.206325562 +0000] conn=17279184 op=77 SRCH base="cn=hbac,dc=ipa,dc=example,dc=com" scope=2 filter="(objectClass=ipaHBACServiceGroup)" attrs="objectClass cn ipaUniqueID member memberOf"
[20/Nov/2017:12:20:25.208441520 +0000] conn=17279184 op=78 SRCH base="cn=hbac,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=ipaHBACRule)(ipaEnabledFlag=TRUE)(accessRuleType=allow)(|(hostCategory=all)(memberHost=fqdn=phx-entl01.ipa.example.com,cn=computers,cn=accounts,dc=ipa,dc=example,dc=com)(memberHost=cn=ipaservers,cn=hostgroups,cn=accounts,dc=ipa,dc=example,dc=com)(memberHost=cn=Replication Administrators,cn=privileges,cn=pbac,dc=ipa,dc=example,dc=com)(memberHost=cn=Add Replication Agreements,cn=permissions,cn=pbac,dc=ipa,dc=example,dc=com)(memberHost=cn=Modify Replication Agreements,cn=permissions,cn=pbac,dc=ipa,dc=example,dc=com)(memberHost=cn=Read Replication Agreements,cn=permissions,cn=pbac,dc=ipa,dc=example,dc=com)(memberHost=cn=Remove Replication Agreements,cn=permissions,cn=pbac,dc=ipa,dc=example,dc=com)(memberHost=cn=Modify DNA Range,cn=permissions,cn=pbac,dc=ipa,dc=example,dc=com)(memberHost=cn=Read PassSync Managers Configuration,cn=permissions,cn=pbac,dc=ipa,dc=example,dc=com)(memberHost=cn=Modify PassSync Managers Configuration,cn=permissions,cn=pbac,dc=ipa,dc=example,dc=com)(memberHost=cn=Read LDBM Database Co..." attrs="objectClass cn ipaUniqueID ipaEnabledFlag accessRuleType memberUser userCategory memberService serviceCategory sourceHost sourceHostCategory externalHost memberHost hostCategory"
[20/Nov/2017:12:20:25.250427144 +0000] conn=17292638 op=3 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=louis.abel@ad.example..com,cn=users,cn=compat,dc=ipa,dc=example,dc=com"
[20/Nov/2017:12:20:25.252738753 +0000] conn=17292462 op=10 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.254261006 +0000] conn=17292462 op=11 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.307624551 +0000] conn=17292678 op=1 BIND dn="uid=hbac,cn=sysaccounts,cn=etc,dc=ipa,dc=example,dc=com" method=128 version=3
[20/Nov/2017:12:20:25.308037373 +0000] conn=17292678 op=1 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=hbac,cn=sysaccounts,cn=etc,dc=ipa,dc=example,dc=com"
[20/Nov/2017:12:20:25.313676135 +0000] conn=17292462 op=12 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.315662961 +0000] conn=17292462 op=13 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel@ad.example..com))" attrs=ALL
[20/Nov/2017:12:20:25.317142980 +0000] conn=17292462 op=14 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixGroup)(|(memberUid=louis.abel@ad.example..com)(uniqueMember=uid=louis.abel,cn=users,cn=compat,dc=ipa,dc=example,dc=com)))" attrs="gidNumber"
[20/Nov/2017:12:20:25.392159570 +0000] conn=17292462 op=18 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.395337270 +0000] conn=17292462 op=19 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.397116778 +0000] conn=17292462 op=20 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.400188699 +0000] conn=17292462 op=21 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.586539666 +0000] conn=17292688 op=2 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel@ad.example..com))" attrs=ALL
[20/Nov/2017:12:20:25.588264200 +0000] conn=17292688 op=3 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixGroup)(|(memberUid=louis.abel@ad.example..com)(uniqueMember=uid=louis.abel,cn=users,cn=compat,dc=ipa,dc=example,dc=com)))" attrs="gidNumber"
[20/Nov/2017:12:20:25.599365131 +0000] conn=17292462 op=23 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel@ad.example..com))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.608891685 +0000] conn=14635 op=27 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel@ad.example..com))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.614348376 +0000] conn=14635 op=28 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel@ad.example..com))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.615646497 +0000] conn=14635 op=29 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel@ad.example..com))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.617009559 +0000] conn=14635 op=30 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel@ad.example..com))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
[20/Nov/2017:12:20:25.618405995 +0000] conn=14635 op=31 SRCH base="cn=compat,dc=ipa,dc=example,dc=com" scope=2 filter="(&(objectClass=posixAccount)(uid=louis.abel@ad.example..com))" attrs="uid userPassword uidNumber gidNumber cn homeDirectory loginShell gecos description objectClass"
jhrozek commented 6 years ago

I tried to relax the group resolving conditions in the 1.2 release I just published. Could you give that a try? If that still doesn't work, let's try some more debugging..

nazunalika commented 6 years ago

It looks like it's working. As far as I can tell. I'll recompile on a Solaris 10 system and see what happens also, just in case, even though it was working on Solaris 10 before. I'll have it at the end of this comment.

Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account): ph_get_hbac_rules: OK
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account): [< hbac_evaluate()
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):   REQUEST:
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           service [sshd]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           service_group:
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):                   [default_login_services]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):                   [default_login_services_all]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):                   [default_login_services_legacy]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           user [louis.abel@ad.example.com] 
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           user_group:
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):                   [aocusers]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):                   [infrasadm]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):                   [unixadm] 
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           targethost [qadesftp.example.com]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           targethost_group (none)
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):   srchost (none)
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           request time 2018-01-17 16:30:24
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):   RULE [All_UNIX] [ENABLED]:
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):   services:
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           category [0x1] [ALL]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           services_names (none)
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           services_groups (none)
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):   users:
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           category [0] [NONE]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           users_names (none)
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           users_groups:
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):                   [unixadm]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):   targethosts:
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           category [0x1] [ALL]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           targethosts_names (none)
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           targethosts_groups (none)
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):   srchosts:
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           category [0x1] [ALL]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           srchosts_names (none)
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account):           srchosts_groups (none)
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account): ALLOWED by rule [All_UNIX].
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account): hbac_evaluate() >]
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account): Allowing access
Jan 17 16:30:24 qadesftp sshd[23921]: pam_hbac(sshd:account): returning [0]: Success
Jan 17 16:30:24 qadesftp sshd[23921]: Accepted password for louis.abel from 172.20.55.80 port 50360 ssh2

Here's an example denial also. 

Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account): ph_get_hbac_rules: OK
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account): [< hbac_evaluate()
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):   REQUEST:
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           service [sshd]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           service_group:
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):                   [default_login_services]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):                   [default_login_services_all]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):                   [default_login_services_legacy]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           user [milo.zaragoza@ad.example.com] 
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           user_group:
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):                   [aocusers]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):                   [infrasadm]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):                   [operations]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):                   [weblogicadm]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           targethost [qadesftp.example.com]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           targethost_group (none)
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):   srchost (none)
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           request time 2018-01-17 16:34:31 
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):   RULE [All_UNIX] [ENABLED]:
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):   services:
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           category [0x1] [ALL]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           services_names (none)
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           services_groups (none)
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):   users:
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           category [0] [NONE]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           users_names (none)
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           users_groups:
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):                   [unixadm]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):   targethosts:
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           category [0x1] [ALL]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           targethosts_names (none)
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           targethosts_groups (none)
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):   srchosts:
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           category [0x1] [ALL]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           srchosts_names (none)
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account):           srchosts_groups (none)
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account): The rule [All_UNIX] did not match.
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account): hbac_evaluate() >]
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account): Denying access
Jan 17 16:34:32 qadesftp sshd[23965]: pam_hbac(sshd:account): returning [6]: Permission denied
Jan 17 16:34:32 qadesftp sshd[23969]: fatal: Access denied for user milo.zaragoza by PAM account configuration

It appears on Solaris 10, something is now broken. (I can't test this on Solaris 11 yet, still waiting for Oracle's patch)

[louis.abel@diurne ~]$ ssh phdevu15
Password: 
Connection closed by UNKNOWN port 65535
[louis.abel@diurne ~]$ 

---

Jan 17 10:38:29 phdevu15 sshd[10005]: [ID 541005 auth.debug] ignore_authinfo_unavail found
Jan 17 10:38:29 phdevu15 sshd[10005]: [ID 541005 auth.debug] ignore_unknown_user found
Jan 17 10:38:29 phdevu15 sshd[10005]: [ID 884530 auth.debug] debug option found
Jan 17 10:38:29 phdevu15 sshd[10005]: [ID 879566 auth.debug] config file: /etc/pam_hbac.conf

If I have the module enabled, it never gets passed this point. As soon as I disable pam_hbac in pam.conf I can login fine. I fell back to an old git clone I had some time ago and it seems to be working again. I don't know how to find when I did the clone. The date of the source files that I cloned say May 7th if that's any indication.

Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 165856 auth.debug] ph_get_hbac_rules: OK
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 596282 auth.notice] [< hbac_evaluate()
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 596282 auth.notice] [< hbac_evaluate()
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 596282 auth.notice] [< hbac_evaluate()
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 113345 auth.debug]    REQUEST:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 457029 auth.debug]            service [sshd-kbdint]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 261669 auth.debug]            service_group:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 311089 auth.debug]                    [default_login_services]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 311089 auth.debug]                    [default_login_services_all]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 311089 auth.debug]                    [default_login_services_legacy]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 457029 auth.debug]            user [louis.abel@ad.example.com]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 261669 auth.debug]            user_group:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 311089 auth.debug]                    [chiusers]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 311089 auth.debug]                    [infrasadm]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 311089 auth.debug]                    [unixadm]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 457029 auth.debug]            targethost [phdevu15.example.com]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 261669 auth.debug]            targethost_group:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 311089 auth.debug]                    [legacy]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 407992 auth.debug]    srchost (none)
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 616581 auth.debug]            request time 2018-01-17 11:28:30
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 465512 auth.debug]    RULE [All_UNIX] [ENABLED]:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 420269 auth.debug]    services:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 208892 auth.debug]            category [0x1] [ALL]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 361700 auth.debug]            services_names (none)
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 481103 auth.debug]            services_groups (none)
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 176057 auth.debug]    users:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 208892 auth.debug]            category [0] [NONE]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 361700 auth.debug]            users_names (none)
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 647537 auth.debug]            users_groups:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 311089 auth.debug]                    [unixadm]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 244076 auth.debug]    targethosts:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 208892 auth.debug]            category [0x1] [ALL]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 361700 auth.debug]            targethosts_names (none)
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 481103 auth.debug]            targethosts_groups (none)
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 109348 auth.debug]    srchosts:
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 208892 auth.debug]            category [0x1] [ALL]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 361700 auth.debug]            srchosts_names (none)
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 481103 auth.debug]            srchosts_groups (none)
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 282544 auth.notice] ALLOWED by rule [All_UNIX].
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 282544 auth.notice] ALLOWED by rule [All_UNIX].
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 282544 auth.notice] ALLOWED by rule [All_UNIX].
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 559000 auth.notice] hbac_evaluate() >]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 559000 auth.notice] hbac_evaluate() >]
Jan 17 11:28:30 phdevu15 sshd[24294]: [ID 559000 auth.notice] hbac_evaluate() >]

The configure options I used for 1.2 as a reference (and steps):

# /opt/csw/bin/pkgutil -i -y libnet ar binutils gcc4g++ glib2 libglib2_dev gmake
# PATH=$PATH:/opt/csw/bin
# export M4=/opt/csw/bin/gm4
# autoconf -o configure
# autoreconf -i
# ./configure AR=/opt/csw/bin/gar --with-pammoddir=/usr/lib/security --sysconfdir=/etc/ --disable-ssl --disable-man-pages
# make
# make install

I disable SSL otherwise, pam_hbac cannot communicate properly with the IPA server.

nazunalika commented 6 years ago

I went and compiled 1.2 on Solaris 11. Oracle finally released the fix so I can login with short names into Solaris 11 for users in AD. However, I'm getting segfaults, which is unfortunate. I cannot tell if it's a problem with Solaris or a problem with the module.

(gdb) bt
#0  0xf35abeb0 in strlen () from /lib/libc.so.1
#1  0xf35fab4c in _ndoprnt () from /lib/libc.so.1
#2  0xf35fd080 in vsnprintf () from /lib/libc.so.1
#3  0xf35e817c in vsyslog () from /lib/libc.so.1
#4  0xf17a85f0 in logger (pamh=pamh@entry=0x7ee038, level=level@entry=5, fmt=0xf17a2f28 "Hostname %s is not qualified, make sure HOST_NAME is set\n") at src/pam_hbac_utils.c:102
#5  0xf17a5e4c in warn_unqualified_hostname (hostname=0x7f0730 "phdevu16", pamh=0x7ee038) at src/pam_hbac_config.c:129
#6  default_config (conf=0x789cb0, pamh=0x7ee038) at src/pam_hbac_config.c:143
#7  ph_read_config (pamh=pamh@entry=0x7ee038, config_file=<optimized out>, _conf=_conf@entry=0x809b4c) at src/pam_hbac_config.c:331
#8  0xf17a4c44 in ph_init (config_file=0x0, pamh=0x7ee038) at src/pam_hbac.c:240
#9  pam_hbac (action=PAM_HBAC_ACCOUNT, pam_flags=<optimized out>, argv=<optimized out>, argc=<optimized out>, pamh=0x7ee038) at src/pam_hbac.c:332
#10 pam_sm_acct_mgmt (pamh=0x7ee038, flags=<optimized out>, argc=<optimized out>, argv=<optimized out>) at src/pam_hbac.c:480
#11 0xf22a4aa0 in run_stack () from /lib/libpam.so.1
#12 0xf22a4ff4 in pam_acct_mgmt () from /lib/libpam.so.1
#13 0x0003f220 in do_pam_kbdint ()
#14 0x0003f14c in auth2_pam ()
#15 0x0003ecd0 in userauth_kbdint ()
#16 0x0003babc in input_userauth_request ()
#17 0x0005aac4 in dispatch_run ()
#18 0x0003b688 in do_authentication2 ()
#19 0x00037288 in main ()
URI = ldap://phx-entl01.ipa.example.com
BASE = dc=ipa,dc=example,dc=com
BIND_DN = uid=hbac,cn=sysaccounts,cn=etc,dc=ipa,dc=example,dc=com
BIND_PW = joyTHGgrtDq4t
HOST_NAME = phdevu16.example.com

What's iffy is that this happens on 1.1 release, May 6th commit, and 1.2 release.

Solaris 10, 1.2 still does not work. The may 6th commit is what still works for me.

Summary: Solaris 10: May 6th (37fbad9) commit works, 1.2 release fails. Solaris 11: 1.1, May 6th commit, 1.2 release fail.

jhrozek commented 6 years ago

The crash is a bug in pam_hbac. I created https://github.com/jhrozek/pam_hbac/pull/114 for that.

jhrozek commented 6 years ago

are you comfortable with applying PRs to test them? Or would you prefer if I create a test tarball for you?

nazunalika commented 6 years ago

I can apply PR's, that's not a problem.

nazunalika commented 6 years ago

I went and tried out the changes. I end up getting a new backtrace with 11. 

#0  0x636f6d00 in ?? ()
#1  0xe6c5f828 in ldap_get_option () from /usr/lib/libldap.so.5
#2  0xe62f77d8 in start_tls (secure=<optimized out>, ca_cert=0x0, ldap=0x9ce9d8, ph=0x9cb9c8) at src/pam_hbac_ldap.c:370
#3  secure_connection (secure=<optimized out>, ca_cert=0x0, ldap=0x9ce9d8, ph=0x9cb9c8) at src/pam_hbac_ldap.c:515
#4  ph_connect (ctx=ctx@entry=0xa34628) at src/pam_hbac_ldap.c:563
#5  0xe62f4918 in pam_hbac (action=PAM_HBAC_ACCOUNT, pam_flags=<optimized out>, argv=<optimized out>, argc=<optimized out>, pamh=0x9cb9c8) at src/pam_hbac.c:341
#6  pam_sm_acct_mgmt (pamh=0x9cb9c8, flags=<optimized out>, argc=<optimized out>, argv=<optimized out>) at src/pam_hbac.c:480
#7  0xe6e14aa0 in run_stack () from /lib/libpam.so.1
#8  0xe6e14ff4 in pam_acct_mgmt () from /lib/libpam.so.1
#9  0x0003f220 in do_pam_kbdint ()
#10 0x0003f14c in auth2_pam ()
#11 0x0003ecd0 in userauth_kbdint ()
#12 0x0003babc in input_userauth_request ()
#13 0x0005aac4 in dispatch_run ()
#14 0x0003b688 in do_authentication2 ()
#15 0x00037288 in main ()
Feb 27 09:52:31 phdevu16 sshd[5742]: [ID 744475 auth.notice] Hostname phdevu16 is not qualified, make sure HOST_NAME is set
Feb 27 09:52:31 phdevu16 sshd[5742]: [ID 744475 auth.notice] Hostname phdevu16 is not qualified, make sure HOST_NAME is set
Feb 27 09:52:31 phdevu16 sshd[5742]: [ID 805440 auth.notice] This platform does not support TLS!
Feb 27 09:52:31 phdevu16 sshd[5742]: [ID 805440 auth.notice] This platform does not support TLS!

I went and re-ran configure and disabled ssl for Solaris 11 just to see if it'll get further. It unfortunately doesn't and I get similar logs. Backtrace...

#0  0x54482d44 in ?? ()
#1  0xe6c7e568 in ldap_sasl_bind () from /usr/lib/libldap.so.5
#2  0xe6c7e870 in ldap_sasl_bind_s () from /usr/lib/libldap.so.5
#3  0xe6307390 in ph_connect (ctx=ctx@entry=0xa34628) at src/pam_hbac_ldap.c:580
#4  0xe63045f8 in pam_hbac (action=PAM_HBAC_ACCOUNT, pam_flags=<optimized out>, argv=<optimized out>, argc=<optimized out>, pamh=0x9cb9c8) at src/pam_hbac.c:341
#5  pam_sm_acct_mgmt (pamh=0x9cb9c8, flags=<optimized out>, argc=<optimized out>, argv=<optimized out>) at src/pam_hbac.c:480
#6  0xe6e24aa0 in run_stack () from /lib/libpam.so.1
#7  0xe6e24ff4 in pam_acct_mgmt () from /lib/libpam.so.1
#8  0x0003f220 in do_pam_kbdint ()
#9  0x0003f14c in auth2_pam ()
#10 0x0003ecd0 in userauth_kbdint ()
#11 0x0003babc in input_userauth_request ()
#12 0x0005aac4 in dispatch_run ()
#13 0x0003b688 in do_authentication2 ()
#14 0x00037288 in main ()

For Solaris 10...it looks like it works. In both /var/adm/messages and /var/log/authlog, I end up seeing an auth.error log, "missing attributes: 1" and then "skipping malformed rule 3/3" in /var/log/authlog. (Note: I don't think those are related. I'm unsure if those are some other issue with my rules somewhere since it's not telling me which rules are missing attributes or what's malformed.)

Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 596282 auth.notice] [< hbac_evaluate()
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 596282 auth.notice] [< hbac_evaluate()
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 860216 auth.debug] Setting category ALL for host
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 978831 auth.debug] Found 0 members
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 795423 auth.error] Missing attributes: 1
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 894429 auth.warning] Skipping malformed rule 3/3
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 165856 auth.debug] ph_get_hbac_rules: OK
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 596282 auth.notice] [< hbac_evaluate()
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 113345 auth.debug]    REQUEST:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 457029 auth.debug]            service [sshd-kbdint]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 261669 auth.debug]            service_group:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 311089 auth.debug]                    [default_login_services]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 311089 auth.debug]                    [default_login_services_all]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 311089 auth.debug]                    [default_login_services_legacy]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 457029 auth.debug]            user [louis.abel@ad.example.com]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 261669 auth.debug]            user_group:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 311089 auth.debug]                    [chiusers]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 311089 auth.debug]                    [infrasadm]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 311089 auth.debug]                    [unixadm]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 457029 auth.debug]            targethost [phdevu15.example.com]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 261669 auth.debug]            targethost_group:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 311089 auth.debug]                    [legacy]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 407992 auth.debug]    srchost (none)
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 616581 auth.debug]            request time 2018-02-27 09:41:40
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 465512 auth.debug]    RULE [All_UNIX] [ENABLED]:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 420269 auth.debug]    services:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 208892 auth.debug]            category [0x1] [ALL]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 361700 auth.debug]            services_names (none)
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 481103 auth.debug]            services_groups (none)
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 176057 auth.debug]    users:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 208892 auth.debug]            category [0] [NONE]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 361700 auth.debug]            users_names (none)
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 647537 auth.debug]            users_groups:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 311089 auth.debug]                    [unixadm]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 244076 auth.debug]    targethosts:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 208892 auth.debug]            category [0x1] [ALL]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 361700 auth.debug]            targethosts_names (none)
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 481103 auth.debug]            targethosts_groups (none)
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 109348 auth.debug]    srchosts:
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 208892 auth.debug]            category [0x1] [ALL]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 361700 auth.debug]            srchosts_names (none)
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 481103 auth.debug]            srchosts_groups (none)
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 282544 auth.notice] ALLOWED by rule [All_UNIX].
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 282544 auth.notice] ALLOWED by rule [All_UNIX].
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 559000 auth.notice] hbac_evaluate() >]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 282544 auth.notice] ALLOWED by rule [All_UNIX].
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 559000 auth.notice] hbac_evaluate() >]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 559000 auth.notice] hbac_evaluate() >]
Feb 27 09:41:40 phdevu15 sshd[25924]: [ID 881433 auth.debug] Allowing access
nazunalika commented 6 years ago

Below is after a new Solaris 11 system is provisioned with the latest patches.

Program terminated with signal 11, Segmentation fault.
#0  0xf91626b4 in ldap_set_option () from /usr/lib/libldap.so.5
(gdb) bt
#0  0xf91626b4 in ldap_set_option () from /usr/lib/libldap.so.5
#1  0xf87db0f4 in ph_connect () from /usr/lib/security//pam_hbac.so
#2  0xf87d5b88 in pam_hbac () from /usr/lib/security//pam_hbac.so
#3  0xf87d61f8 in pam_sm_acct_mgmt () from /usr/lib/security//pam_hbac.so
#4  0xf9304aa0 in run_stack () from /lib/libpam.so.1
#5  0xf9304ff4 in pam_acct_mgmt () from /lib/libpam.so.1
#6  0x0003f220 in do_pam_kbdint ()
#7  0x0003f14c in auth2_pam ()
#8  0x0003ecd0 in userauth_kbdint ()
#9  0x0003babc in input_userauth_request ()
#10 0x0005aac4 in dispatch_run ()
#11 0x0003b688 in do_authentication2 ()
#12 0x00037288 in main ()
nazunalika commented 6 years ago 
#0  0xef8326b4 in ldap_set_option () from /usr/lib/libldap.so.5
(gdb) bt
#0  0xef8326b4 in ldap_set_option () from /usr/lib/libldap.so.5
#1  0xeee9b0f4 in ph_connect (ctx=0xe0b9b8) at src/pam_hbac_ldap.c:554
#2  0xeee95b88 in pam_hbac (action=PAM_HBAC_ACCOUNT, pamh=0xe08028, 
    pam_flags=0, argc=3, argv=0xdda060) at src/pam_hbac.c:341
#3  0xeee961f8 in pam_sm_acct_mgmt (pamh=0xe08028, flags=0, argc=3, 
    argv=0xdda060) at src/pam_hbac.c:480
#4  0xef9e4aa0 in run_stack () from /lib/libpam.so.1
#5  0xef9e4ff4 in pam_acct_mgmt () from /lib/libpam.so.1
#6  0x0003f220 in do_pam_kbdint ()
#7  0x0003f14c in auth2_pam ()
#8  0x0003ecd0 in userauth_kbdint ()
#9  0x0003babc in input_userauth_request ()
#10 0x0005aac4 in dispatch_run ()
#11 0x0003b688 in do_authentication2 ()
#12 0x00037288 in main ()

(gdb) bt full
#0  0xf59c26b4 in ldap_set_option () from /usr/lib/libldap.so.5
No symbol table info available.
#1  0xf503b0cc in ph_connect (ctx=0xf62b10) at src/pam_hbac_ldap.c:554
        ret = 0
        ld = 0xfcbcc0
        password = {bv_len = 0, bv_val = 0x0}
        ldap_vers = 3
#2  0xf5035b80 in pam_hbac (action=PAM_HBAC_ACCOUNT, pamh=0xfe0fa8, pam_flags=0, argc=3, argv=0xf62ab0) at src/pam_hbac.c:341
        ret = 0
        pam_ret = 0
        flags = 7
        pi = {pam_service = 0xf62ac8 "sshd-kbdint", pam_user = 0xfb2e70 "louis.abel", pam_tty = 0xf66ad8 "sshd", pam_ruser = 0xf5033138 "", 
          pam_rhost = 0xf660b0 "diurne.example.com", pam_service_size = 12, pam_user_size = 11, pam_tty_size = 5, pam_ruser_size = 1, pam_rhost_size = 19}
        ctx = 0xf62b10
        config_file = 0x0
        user = 0x0
        service = 0x0
        targethost = 0x0
        eval_req = 0x0
        rules = 0x0
        hbac_eval_result = 5
        info = 0x0
#3  0xf50361f0 in pam_sm_acct_mgmt (pamh=0xfe0fa8, flags=0, argc=3, argv=0xf62ab0) at src/pam_hbac.c:480
No locals.
#4  0xf5b64aa0 in run_stack () from /lib/libpam.so.1
No symbol table info available.
#5  0xf5b64ff4 in pam_acct_mgmt () from /lib/libpam.so.1
No symbol table info available.
#6  0x0003f220 in do_pam_kbdint ()
No symbol table info available.
#7  0x0003f14c in auth2_pam ()
No symbol table info available.
#8  0x0003ecd0 in userauth_kbdint ()
No symbol table info available.
#9  0x0003babc in input_userauth_request ()
No symbol table info available.
#10 0x0005aac4 in dispatch_run ()
No symbol table info available.
#11 0x0003b688 in do_authentication2 ()
No symbol table info available.
#12 0x00037288 in main ()
No symbol table info available.

Here's a more useful backtrace.

ghost commented 6 years ago

Unsurprisingly, the issue seems to lie in Solaris 11' LDAP library libldap.so. This patch uses only OpenLDAP libldap-2.4.so and the crash disappears:


diff --git i/external/ldap.m4 w/external/ldap.m4
index dfb5a2d..d924098 100644
--- i/external/ldap.m4
+++ w/external/ldap.m4
@@ -8,13 +8,6 @@ AC_DEFUN([AM_CHECK_OPENLDAP],
         fi
     done

-    for p in /usr/lib/openldap /usr/local/lib ; do
-        if test -f "${p}/libldap.so"; then
-            OPENLDAP_LIBS="${OPENLDAP_LIBS} -L${p}"
-            break;
-        fi
-    done
-
     SAVE_CFLAGS=$CFLAGS
     SAVE_LIBS=$LIBS
     CFLAGS="$CFLAGS $OPENLDAP_CFLAGS"
@@ -29,10 +22,10 @@ AC_DEFUN([AM_CHECK_OPENLDAP],
                     #endif
                     ])

-    AC_CHECK_LIB(ldap, ldap_search, with_ldap=yes)
+    AC_CHECK_LIB(ldap-2.4, ldap_search, with_ldap=yes)
     AC_CHECK_LIB(ldap-2.4, ldap_initialize, with_ldap_two_four=yes)
     dnl Check for other libraries we need to link with to get the main routines.
-    test "$with_ldap" != "yes" && { AC_CHECK_LIB(ldap, ldap_open, [with_ldap=yes with_ldap_lber=yes], , -llber) }
+    test "$with_ldap" != "yes" && { AC_CHECK_LIB(ldap-2.4, ldap_open, [with_ldap=yes with_ldap_lber=yes], , -llber) }
     test "$with_ldap_lber" != "yes" && { AC_CHECK_LIB(lber, ber_pvt_opt_on, with_ldap_lber=yes) }

     if test "$with_ldap" = "yes"; then
@@ -42,7 +35,6 @@ AC_DEFUN([AM_CHECK_OPENLDAP],
         if test "$with_ldap_two_four" = "yes" ; then
             OPENLDAP_LIBS="${OPENLDAP_LIBS} -lldap-2.4"
         fi
-        OPENLDAP_LIBS="${OPENLDAP_LIBS} -lldap"
     else
         AC_MSG_ERROR([LDAP libraries not found])
     fi```
nazunalika commented 6 years ago

A more minimal change:

diff --git a/external/ldap.m4 b/external/ldap.m4
index dfb5a2d..e30c205 100644
--- a/external/ldap.m4
+++ b/external/ldap.m4
@@ -41,8 +41,9 @@ AC_DEFUN([AM_CHECK_OPENLDAP],
         fi
         if test "$with_ldap_two_four" = "yes" ; then
             OPENLDAP_LIBS="${OPENLDAP_LIBS} -lldap-2.4"
+        else
+            OPENLDAP_LIBS="${OPENLDAP_LIBS} -lldap"
         fi
-        OPENLDAP_LIBS="${OPENLDAP_LIBS} -lldap"
     else
         AC_MSG_ERROR([LDAP libraries not found])
     fi

I really think that should've been an 'else'

# export CFLAGS="-m32 -gstabs"
# export CXXFLAGS="-m32"
# export LDFLAGS="-m32"
# autoreconf -if
# ./configure --with-pammoddir=/usr/lib/security --mandir=/usr/share/man --sysconfdir=/etc/
# make
# make install
May  4 10:59:00 phdevu16 sshd[19778]: [ID 744475 auth.notice] Hostname devu16 is not qualified, make sure HOST_NAME is set
May  4 10:59:00 phdevu16 sshd[19778]: [ID 744475 auth.notice] Hostname devu16 is not qualified, make sure HOST_NAME is set
May  4 10:59:01 phdevu16 sshd[19778]: [ID 960702 auth.notice] returning 3
May  4 10:59:01 phdevu16 sshd[19778]: [ID 960702 auth.notice] returning 3
May  4 10:59:01 phdevu16 sshd[19778]: [ID 795423 auth.error] Missing attributes: 1
May  4 10:59:01 phdevu16 sshd[19778]: [ID 795423 auth.error] Missing attributes: 1
May  4 10:59:01 phdevu16 sshd[19778]: [ID 894429 auth.warning] Skipping malformed rule 3/3
May  4 10:59:01 phdevu16 sshd[19778]: [ID 894429 auth.warning] Skipping malformed rule 3/3
May  4 10:59:01 phdevu16 sshd[19778]: [ID 596282 auth.notice] [< hbac_evaluate()
May  4 10:59:01 phdevu16 sshd[19778]: [ID 596282 auth.notice] [< hbac_evaluate()
May  4 10:59:01 phdevu16 sshd[19778]: [ID 282544 auth.notice] ALLOWED by rule [All_UNIX].
May  4 10:59:01 phdevu16 sshd[19778]: [ID 282544 auth.notice] ALLOWED by rule [All_UNIX].
May  4 10:59:01 phdevu16 sshd[19778]: [ID 559000 auth.notice] hbac_evaluate() >]
May  4 10:59:01 phdevu16 sshd[19778]: [ID 559000 auth.notice] hbac_evaluate() >]
jhrozek commented 6 years ago

Yes, the if-else seems like a bug. Would you like to submit a PR?

nazunalika commented 6 years ago

I'm not sure if this issue applies here, let me know if I should open a brand new issue for this.

For logins (sshd-kbdinit, others) are working after the PR from a few comments back. However, it seems the issue is also with sudo (both TCMsudo and the sudo from oracle's repos). Below is a bt from a core that gets generated.

#0  0x6f736978 in ?? ()
#1  0xfe6b1f28 in ldap_set_option () from /usr/lib/libldap.so.5
#2  0xfd80b0dc in ph_connect (ctx=0xaa398) at src/pam_hbac_ldap.c:554
#3  0xfd805b70 in pam_hbac (action=PAM_HBAC_ACCOUNT, pamh=0x50f38, pam_flags=-2147483648, argc=3, argv=0x44fe8) at src/pam_hbac.c:341
#4  0xfd8061e0 in pam_sm_acct_mgmt (pamh=0x50f38, flags=-2147483648, argc=3, argv=0x44fe8) at src/pam_hbac.c:480
#5  0xfe6e4aa0 in run_stack () from /lib/libpam.so.1
#6  0xfe6e4ff4 in pam_acct_mgmt () from /lib/libpam.so.1
#7  0xfe75a2cc in sudo_pam_approval (pw=0x0, auth=<optimized out>, exempt=<error reading variable: Unhandled dwarf expression opcode 0x0>) at ./auth/pam.c:211
#8  0xfe75962c in sudo_auth_approval (pw=<error reading variable: DWARF-2 expression error: DW_OP_reg operations must be used either alone or in conjunction with DW_OP_piece or DW_OP_bit_piece.>, validated=<optimized out>, 
    exempt=<error reading variable: Unhandled dwarf expression opcode 0x0>) at ./auth/sudo_auth.c:179
#9  0xfe75b928 in check_user (validated=-25444796, mode=<error reading variable: Unhandled dwarf expression opcode 0x0>) at ./check.c:223
#10 0xfe7724f0 in sudoers_policy_main (argc=1, argv=0xffbff340, pwflag=0, env_add=<error reading variable: Asked for position 0 of stack, stack only has 0 elements on it.>, verbose=<optimized out>, closure=0x247) at ./sudoers.c:382
#11 0xfe76c5c4 in sudoers_policy_check (argc=<error reading variable: Unhandled dwarf expression opcode 0x0>, argv=<error reading variable: Unhandled dwarf expression opcode 0x0>, env_add=<optimized out>, 
    command_infop=<error reading variable: Unhandled dwarf expression opcode 0x1>, argv_out=<optimized out>, user_env_out=<error reading variable: Unhandled dwarf expression opcode 0x0>) at ./policy.c:861
#12 0x00023eb8 in main (argc=<error reading variable: dwarf2_find_location_expression: Corrupted DWARF expression.>, argv=<error reading variable: Unhandled dwarf expression opcode 0x2>, 
    envp=<error reading variable: Unhandled dwarf expression opcode 0x2>) at ./sudo.c:1158

As it stands, I do not know if this is a problem directly within sudo or a problem within pam_hbac. If this is directly a sudo problem, I can see about filing a bug report with them.

Presently, my only way around this is to put this in /etc/pam.d/sudo to avoid the account required pam_hbac line in /etc/pam.d/other from being called:

account required        pam_allow.so.1