Authorization Fails after Cache Expiry

90 views
Skip to first unread message

Carter

unread,
Apr 23, 2024, 2:05:21 PMApr 23
to Event-Driven Servers
Hello,
I'm using tac_plus-ng with the "mavis_tacplus-ng_ldap.pl" LDAP backend. In my testing, I've found that when I first authenticate and log into a device, there are no problems and my commands are authorized successfully. However, after "mavis cache timeout" expires, rules using "member == xyz" and "memberof =~ /xyz/" no longer recognize my LDAP group membership, causing authorization to fail. In a packet capture, I see the tacacs server reach out to the LDAP server again and it is able to retrieve my group information, but the "member == xyz" check returns false and authorization fails regardless.

Is this behavior intentional? Is there any downside to raising the "mavis cache timeout" value to a high value like 12 hours to avoid this, or is there a better solution? This is my configuration:

id = spawnd {
        background = no
        # single process = yes
        listen { address = 0.0.0.0 port = 49 }
        spawn {
                instances min = 1
                instances max = 32
                sticky cache period = 86400
        }
}

id = tac_plus-ng {
        # debug = PACKET AUTHEN AUTHOR
        debug = ALL -PACKET -HEX

        # log mysyslog
        log accesslog { destination = /tmp/tac_authentication.log }
        log authorlog { destination = /tmp/tac_authorization.log }
        log acctlog { destination = /tmp/tac_accounting.log }

        access log = accesslog
        authorization log = authorlog
        accounting log = acctlog

        include = /home/tacplus/include/realms
        include = /home/tacplus/include/nets

        mavis module = groups {
                groups filter = /^.+$/
                memberof filter = /^cn=/ # use this as a prefix
        }

        mavis module = external {
                setenv LDAP_SERVER_TYPE = "generic"
                setenv LDAP_HOSTS = "..."
                setenv LDAP_BASE = "..."
                setenv LDAP_SCOPE = "sub"
                setenv LDAP_USER = "..."
                setenv LDAP_PASSWD = "..."
                setenv LDAP_FILTER = "(&(uid=%s)(objectclass=xyzuser))"
                setenv LDAP_FILTER_GROUP = "(&(objectClass=xyzgroup)(member=%s))"
                exec = /usr/local/lib/mavis/mavis_tacplus-ng_ldap.pl

        }

        mavis cache timeout = 60

        user backend = mavis
        login backend = mavis
        pap backend = mavis

        net private {
                net rfc1918 { address = 10.0.0.0/8,172.16.0.0/12 address = 192.168.0.0/16 }
                net local { address = 127.0.0.1 }
        }

        device newworld {
                address = ::/0

                device world {
                        address = 0.0.0.0/0
                        # welcome banner = "Welcome\n"
                        enable 15 = clear secret
                        key = "..."
                        device rfc {
                                address = 172.16.0.0/12
                                address = 10.0.0.1
                                # welcome banner = "Welcome, you're coming from ${client.address}\n"
                        }
                        # parent = rfc
                }
        }

        profile engineering {
                # enable 2 = permit
                # enable 14 = clear demodemo
                # enable 15 = login
                script {
                        # if ("${cmd}" != "")
                                # message = "commandline=${cmd}"
                        if (service == shell) {
                                if (cmd == "") {
                                        # shell startup
                                        set priv-lvl = 15
                                        permit
                                }
                                if (cmd =~ /^healthcheck.*/) {
                                        permit
                                }
                                if (cmd =~ /^show cdp .+/) { message = "not now" deny }
                                # if (device == lab) deny
                                permit
                        }
                        # if (service == demo) {
                                # set test = too
                                # permit
                        # }
                }
        }

        profile guest {
                script {
                        if (service == shell) {
                                set priv-lvl = 1
                                permit
                        }
                        deny
                }
        }

        group readonly {
        }

        group engineering {
        }

        group alldevices-exec

        user demo {
                password login = clear "..."
                # password pap = login
                member = engineering
        }

        user readonly {
                password {
                        # pap = clear readonly
                        login = clear readonly
                }
                member = readonly
        }

        ruleset {
                rule mainrule {
                        enabled = yes
                        script {
#                               if (memberof =~ /^cn=alldevices-exec,/){  # both memberof and member fail after cache timeout
                                if (member == alldevices-exec){
                                        profile = engineering
                                        permit
                                }
                                deny
                        }
                }
        }
}

Any help is much appreciated.

Carter

Marc Huber

unread,
Apr 24, 2024, 11:35:00 AMApr 24
to event-driv...@googlegroups.com
Hi Carter,

I don't think there's a general problem here, I've just tested this and
the backend query did finely refresh user data after cache expiration.

Does your LDAP_USER have sufficient access to the attributes of other
users? The initial LDAP attribute query (just after user authentication)
will run after authenticating with the queried user's credentials, but
for authorization-only LDAP_USER will be used, and this may make a
difference in the attributes available, depending on your LDAP server
implemenations.

Cheers,

Marc

Carter

unread,
May 1, 2024, 11:00:51 AMMay 1
to Event-Driven Servers
Marc,
It looks like the backend script is binding as the LDAP_USER and looking up the queried user's group membership information before the queried user's password is ever sent to the LDAP server. Based on my packet capture, binding as the queried user is the final LDAP operation that happens when logging into the NAS. When I try to run a command on the NAS after the mavis cache expires, the script binds as LDAP_USER again before making any LDAP requests, so I don't think there's any LDAP requests being made as the queried user at any point; they would all be made as LDAP_USER.

The only differences I see with the LDAP requests on first authentication versus the LDAP requests after the cache expires are:
- On first authentication, queries "<ROOT>" for some server attributes
- After the cache expires, it doesn't do a recursive lookup on each of my user's groups. I don't think this matters since there aren't any nested groups on my LDAP server.

Even if I log out of the NAS and wait 5 minutes (mavis cache timeout is set to 1 minute), I can't log back in until I restart tac_plus-ng. The LDAP backend returns an ACK, but my user fails the group check despite looking up the groups.

Thanks,
Carter

Marc Huber

unread,
May 4, 2024, 7:27:37 AMMay 4
to event-driv...@googlegroups.com
Hi Carter,

alas, I can't reproduce the issue you're seeing. Could you please share
debug logs or tactrace.pl output? Suggested debug level is 4195106.

Cheers,

Marc

Carter

unread,
May 6, 2024, 10:50:25 AMMay 6
to Event-Driven Servers
Marc,
Attached are the debug logs with debug level set to 4195106. One thing of note, I needed to modify the mavis_tacplus-ng_ldap.pl to comment this part out:

                #my $vendor = $ldap->root_dse->get_value('vendorname');
                #if (defined($vendor) && $vendor =~ /389 Project/ && $#LDAP_BIND < 0) {
                #       printf STDERR "The 389 directory server will not return the memberOf attribute for anonymous binds. " .
                #                     "Please set the LDAP_USER and LDAP_PASSWD environment variables.\n";
                #}


Before commenting this out, I was getting this error: "Can't call method "get_value" on an undefined value at /usr/local/lib/mavis/mavis_tacplus-ng_ldap.pl line 319, <> chunk 1."

Thanks,
Carter
logs-240506.txt

Marc Huber

unread,
May 6, 2024, 12:13:48 PMMay 6
to event-driv...@googlegroups.com
Hi Carter,

what debug level was set for your test? This

> 940339: 14:20:24.288 0/6b9e0eb8: 172.19.19.205 looking for user carter
> in MAVIS backend
> 940339: 14:20:24.381 0/6b9e0eb8: 172.19.19.205 result for user carter
> is ACK
> 940339: 14:20:24.381 0/6b9e0eb8: 172.19.19.205 evaluating ACL mainrule

doesn't show the "user found by MAVIS backend, av pairs:" that I'd
expect so see. 4195106 isn't a random number, but equals to 4194304
(DEBUG_TACTRACE_FLAG) + 802 (a summary of other flags). Please retry
your tests with a debug value of "-1".

Cheers,

Marc
Message has been deleted

Carter

unread,
May 6, 2024, 4:11:12 PMMay 6
to Event-Driven Servers
Marc,
My mistake, I set the debug level for tac_plus-ng instead of spawnd. The debug value you suggested didn't show AV pairs, so I set it to "debug = ALL -PARSE -HEX".
New logs are attached.

In the successful authentication attempt, the queried user's groups are listed under the MEMBEROF and TACMEMBER AV pairs. In the packet capture these are not actually returned in the queried user's attributes (neither for the successful attempt nor the failed ones), so my understanding is that these are parsed from the subsequent LDAP group query based on the "groups filter" and "memberof filter" configuration options and inserted into the list of AV pairs by the LDAP backend script during processing.

After the mavis cache expires, the AV pairs in the debug output don't show the MEMBEROF or TACMEMBER AV pairs. In the packet capture, both on the successful attempt and the failed attempt, the backend script makes an LDAP request using the LDAP_FILTER_GROUP format: "(&(objectClass=xyzgroup)(member=uid=carter,ou=employees,dc=mydomain,dc=net))" and receives a list of group DNs in response. My best guess is that the group membership data is getting inserted into the user's AV pairs by the backend script on the first authentication, but not on subsequent authentication attempts after the mavis cache expires.

Thanks,
Carter
logs-240506-2.txt

Marc Huber

unread,
May 7, 2024, 12:43:59 PMMay 7
to event-driv...@googlegroups.com
Hi Carter,

thanks for testing again.

Alas, I still don't catch why only the first lookup results in

942013: 18:33:07.639 0/4f7c8606: 172.19.19.205 TACMEMBER (len: 17):
"alldevices-exec"
942013: 18:33:07.639 0/4f7c8606: 172.19.19.205 MEMBEROF (len: 451):
"cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net"

and the second lookup doesn't. Could you please set the environment
variables in shell context and then run both

  printf "0 TACPLUS\n4 $USER\n8 $PASS\n49 AUTH\n=\n" |
/path/to/mavis_tacplus-ng_ldap.pl

and

  printf "0 TACPLUS\n4 $USER\n49 INFO\n=\n" |
/path/to/mavis_tacplus-ng_ldap.pl

Both should return the very same memberof attributes.

Thanks,

Marc



On 06.05.2024 21:00, Carter wrote:
> Marc,
> My mistake, I set the debug level for tac_plus-ng instead of spawnd.
> The debug value you suggested didn't show AV pairs, so I set it to
> "debug = ALL -PARSE -HEX".
> New logs are attached.
>
> In the successful authentication attempt, the queried user's groups
> are listed under the MEMBEROF and TACMEMBER AV pairs. In the packet
> capture these are not actually returned in the queried user's
> attributes (neither for the successful attempt nor the failed ones),
> so my understanding is that these are parsed from the subsequent LDAP
> group query based on the "groups filter" and "memberof filter"
> configuration options and inserted into the list of AV pairs by the
> LDAP backend script during processing.
>
> After the mavis cache expires, the AV pairs in the debug output don't
> show the MEMBEROF or TACMEMBER AV pairs. In the packet capture, both
> on the successful attempt and the failed attempt, the backend script
> makes an LDAP request using the LDAP_FILTER_GROUP format:
> "(&(objectClass=xyzgroup)(member=uid=cmerrill,ou=employees,dc=mydomain,dc=net))"
> and receives a list of group DNs in response. My best guess is that
> the group membership data is getting inserted into the user's AV pairs
> by the backend script on the first authentication, but not on
> subsequent authentication attempts after the mavis cache expires.
>
> Thanks,
> Carter
>
> On Monday, May 6, 2024 at 12:13:48 PM UTC-4 Marc Huber wrote:
>
> Hi Carter,
>
> what debug level was set for your test? This
>
> > 940339: 14:20:24.288 0/6b9e0eb8: 172.19.19.205 looking for user
> carter
> > in MAVIS backend
> > 940339: 14:20:24.381 0/6b9e0eb8: 172.19.19.205 result for user
> carter
> > is ACK
> > 940339: 14:20:24.381 0/6b9e0eb8: 172.19.19.205 evaluating ACL
> mainrule
>
> doesn't show the "user found by MAVIS backend, av pairs:" that I'd
> expect so see. 4195106 isn't a random number, but equals to 4194304
> (DEBUG_TACTRACE_FLAG) + 802 (a summary of other flags). Please retry
> your tests with a debug value of "-1".
>
> Cheers,
>
> Marc
>
>
> On 06.05.2024 16:50, Carter wrote:
> > Marc,
> > Attached are the debug logs with debug level set to 4195106. One
> thing
> > of note, I needed to modify the mavis_tacplus-ng_ldap.pl
> <http://mavis_tacplus-ng_ldap.pl> to comment
> > this part out:
> >
> >                 #my $vendor =
> $ldap->root_dse->get_value('vendorname');
> >                 #if (defined($vendor) && $vendor =~ /389
> Project/ &&
> > $#LDAP_BIND < 0) {
> >                 #       printf STDERR "The 389 directory server
> will
> > not return the memberOf attribute for anonymous binds. " .
> >                 #                     "Please set the LDAP_USER and
> > LDAP_PASSWD environment variables.\n";
> >                 #}
> >
> >
> > Before commenting this out, I was getting this error: "Can't call
> > method "get_value" on an undefined value at
> > /usr/local/lib/mavis/mavis_tacplus-ng_ldap.pl
> <http://mavis_tacplus-ng_ldap.pl> line 319, <> chunk 1."
> >
> > Thanks,
> > Carter
> >
>
> --
> You received this message because you are subscribed to the Google
> Groups "Event-Driven Servers" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to event-driven-ser...@googlegroups.com.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/event-driven-servers/169039db-c8e3-4a1a-a520-2c7185d0ebben%40googlegroups.com
> <https://groups.google.com/d/msgid/event-driven-servers/169039db-c8e3-4a1a-a520-2c7185d0ebben%40googlegroups.com?utm_medium=email&utm_source=footer>.

Carter

unread,
May 8, 2024, 1:47:41 PMMay 8
to Event-Driven Servers
Marc,
I appreciate your help. In your test environment, does the LDAP server return the tacMember and/or memberOf attributes as part of the user query (LDAP_FILTER), or are your groups being gathered from the separate group membership query (LDAP_FILTER_GROUP) afterwards? For my environment it's the latter, not sure if that could cause different behavior. Here is the output of those commands.

printf "0 TACPLUS\n4 carter\n8 mypassword\n49 AUTH\n=\n" | /home/tacplus/mavis_tacplus-ng_ldap-custom.pl
0 TACPLUS
1 "cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net"
4 carter
5 uid=carter,ou=employees,dc=mydomain,dc=net
6 ACK
8 mypassword
9 70463
10 25000
19 /home/carter
47 "alldevices-exec","xxxx","xxxx","xxxx","xxxx","xxxx","xxxx"
49 AUTH
52 1
54 /usr/bin/sh
=0


printf "0 TACPLUS\n4 $USER\n49 INFO\n=\n" | /home/tacplus/mavis_tacplus-ng_ldap-custom.pl
0 TACPLUS
1 "cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net"
4 carter
5 uid=carter,ou=employees,dc=mydomain,dc=net
6 ACK
9 70463
10 25000
19 /home/carter
47 "alldevices-exec","xxxx","xxxx","xxxx","xxxx","xxxx","xxxx"
49 INFO
54 /usr/bin/sh
=0

Thanks,
Carter

Marc Huber

unread,
May 8, 2024, 2:08:01 PMMay 8
to event-driv...@googlegroups.com
Hi Carter,

thanks again for testing!

The initial memberOf attributes are from the primary LDAP user query,
and what follows is a recursive lookup on these memberOf groups for
nested group memberships.

The memberOf attributes (#1) look just fine for both authentication or
authorization. Does

printf "0 TACPLUS\n4 carter\n8 mypassword\n49 AUTH\n=\n0 TACPLUS\n4
$USER\n49 INFO\n=\n" | /home/tacplus/mavis_tacplus-ng_ldap-custom.pl |
grep "^1 "

look fine too? There's an unlikely chance that just some first iteration
of the loop works fine, but the next ones fails.

Next thing I'd try would be removing "mavis module = groups { ... }"
from the configuration. While that one doesn't seem suspicious at all,
removing it might help to isolate the problem.

Thanks,

Marc

Carter

unread,
May 8, 2024, 3:28:13 PMMay 8
to Event-Driven Servers
Marc,
Yes, that command outputs the same list of group DNs as the other two commands. I commented out the "mavis module = groups" block without any success, the only difference I see in the logs is that the value of the "IDENTITY_SOURCE" VA pair changed from 2 to 1.

Thanks,
Carter

Carter

unread,
May 8, 2024, 3:30:21 PMMay 8
to Event-Driven Servers
Marc,
Actually this is the full output of that command:

0 TACPLUS
1 "cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net","cn=xxxx,ou=xyzgroups,dc=mydomain,dc=net"
4 carter
5 uid=carter,ou=employees,dc=mydomain,dc=net
6 ACK
8 mypassword
9 70463
10 25000
19 /home/carter
47 "xxxx","xxxx","xxxx","xxxx","xxxx","xxxx","xxxx"

49 AUTH
52 1
54 /usr/bin/sh
=0
0 TACPLUS

4 carter
5 uid=carter,ou=employees,dc=mydomain,dc=net
6 ACK
9 70463
10 25000
19 /home/carter
49 INFO
54 /usr/bin/sh
=0

So the INFO portion doesn't contain the group information.

Marc Huber

unread,
May 8, 2024, 4:07:50 PMMay 8
to event-driv...@googlegroups.com
Hi Carter,

thanks ... this indeed looks like a problem with connection rebinding
... does forcefully closing and reopening the LDAP connection improve
things?

--- a/mavis/perl/mavis_tacplus-ng_ldap.pl
+++ b/mavis/perl/mavis_tacplus-ng_ldap.pl
@@ -268,6 +268,11 @@ while ($in = <>) {
                goto fatal;
        }

+       if ($ldap) {
+               $ldap->unbind;
+               $ldap->disconnect;
+               $ldap = undef;
+       }
        if ($ldap) {
 # Cached LDAP connection still available?
                my $sock = $ldap->socket();

What LDAP server type is that actually? I think I've checked with AD,
OpenLDAP and 389 DS (FreeIPA, more exactly) without seeing any issues.

Cheers,

Marc
> ew this discussion on the web visit
> https://groups.google.com/d/msgid/event-driven-servers/2ca335ad-4a80-4948-b32d-a81e8fb0bc6fn%40googlegroups.com
> <https://groups.google.com/d/msgid/event-driven-servers/2ca335ad-4a80-4948-b32d-a81e8fb0bc6fn%40googlegroups.com?utm_medium=email&utm_source=footer>.

Carter

unread,
May 8, 2024, 4:32:53 PMMay 8
to Event-Driven Servers
Marc,
I added that code in and I get the same result, the AUTH response contains the group data but the INFO response does not. The LDAP server is openldap-2.4.40.

Thanks,
Carter

Marc Huber

unread,
May 9, 2024, 3:12:59 AMMay 9
to event-driv...@googlegroups.com
Hi Carter,

just to be sure, this is the current an unmodified version from GIT? And
your Perl modules (Net::LDAP et al.) are current, too?

Nevertheless, I'm sorry, but I'm giving up on trying to debug this
issue. I can't reproduce your results, and I don't think there's a
problem with the Perl script.

Options remaining:

- use mavis_tacplus_ldap.py or ldapmavis-mt instead of
mavis_tacplus-ng_ldap.pl
- query a different LDAP server (AD e.g.) to further isolate the problem
- query from a different client where the support libraries are
guaranteed to be up to date

Cheers,

Marc


On 08.05.2024 22:32, Carter wrote:
> Marc,
> I added that code in and I get the same result, the AUTH response
> contains the group data but the INFO response does not. The LDAP
> server is openldap-2.4.40.
>
> Thanks,
> Carter
>
> On Wednesday, May 8, 2024 at 4:07:50 PM UTC-4 Marc Huber wrote:
>
> Hi Carter,
>
> thanks ... this indeed looks like a problem with connection rebinding
> ... does forcefully closing and reopening the LDAP connection improve
> things?
>
> --- a/mavis/perl/mavis_tacplus-ng_ldap.pl
> <http://mavis_tacplus-ng_ldap.pl>
> +++ b/mavis/perl/mavis_tacplus-ng_ldap.pl
> <http://mavis_tacplus-ng_ldap.pl>
> <https://groups.google.com/d/msgid/event-driven-servers/2ca335ad-4a80-4948-b32d-a81e8fb0bc6fn%40googlegroups.com?utm_medium=email&utm_source=footer>>.
>
>
> --
> You received this message because you are subscribed to the Google
> Groups "Event-Driven Servers" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to event-driven-ser...@googlegroups.com.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/event-driven-servers/df13683c-1f4a-410d-9000-3a19eb7b80den%40googlegroups.com
> <https://groups.google.com/d/msgid/event-driven-servers/df13683c-1f4a-410d-9000-3a19eb7b80den%40googlegroups.com?utm_medium=email&utm_source=footer>.

Carter

unread,
May 9, 2024, 1:55:52 PMMay 9
to Event-Driven Servers
Marc,
Thanks for the help, if you can take a look at one last thing I would appreciate it. I don't know why this affects my environment and not yours, but I think the issue I'm having is a bug in expand_groupOfNames.

My Perl knowledge is minimal, but I did some debugging with print statements and it seems like something to do with scoping of the %H variable. After the first call to expand_groupOfNames, any subsequent calls still have $H pointing to the %H from the previous call, but this only true inside the inner subroutine "expand_groupOfNames_sub". LDAP always does its job and looks up the groups successfully, but the groups are already present in the stale %H from the first call, so they don't get added to @res in subsequent calls. If $H was properly pointed to a new hash with each call to expand_groupOfNames, I believe this would work.

Thanks,

Marc Huber

unread,
May 10, 2024, 7:30:54 AMMay 10
to event-driv...@googlegroups.com
Hi Carter,

thanks for being so persistent! You're absolutely right, I've now
aligned that code to match the one for memberOf handling. I didn't see
this issue myself because my test OpenLDAP server has the memberOf
overlay enabled. Please git pull and retry, the problem should be fixed.

Thanks again,

Marc

Carter

unread,
May 10, 2024, 9:39:51 AMMay 10
to Event-Driven Servers
Marc,
I tested and it works now. Thank you for fixing this!

Carter
Reply all
Reply to author
Forward
0 new messages