Broken if-clause / external module inclusion since Apr., 17 2023 (193d7513)

Question

Broken if-clause / external module inclusion since Apr., 17 2023 (193d7513)

thefallout78 opened this issue a year ago · 9 comments

We have a problem with the call of the externel radius request plugin based on the user login name.
The affected part of the tacacs config is:

        mavis module = external {
                script in  = { if ($USER !~ /^.*\@MYDOMAIN.*$/ ) skip }
                script out = {
                        if ($TYPE == TACPLUS) {
                                if ($TACTYPE == AUTH && $PASSWORD == $DBPASSWORD || $TACTYPE == INFO) {
                                        set $RESULT = ACK
                                        if ($USER =~ /^.*\@MYDOMAIN.*$/ ) {
                                                set $TACPROFILE = "{ member = MYDOMAIN_GROUP }"
                                        }
                                }
                        }
                }
                exec = /usr/local/sbin/radmavis radmavis "authserver=1.2.3.4:5678:mysecret"
        }

With the changes of 193d751 the application log returns:
...@MYDOMAIN ... shell login failed (no such user)
and there is no package being sent to the remote radius host.

With the state of previous d2f48d7 it successfully returns:
...@MYDOMAIN ... shell login succeeded

It seems like the if clause doesn't match anymore for some reason.
Unfortunately the debug logging does not give any hint about the processing or matching of the regex (level 1023).

The change statistics of the relevant commits are:

~/git/event-driven-servers$ git diff d2f48d7b 193d7513 --stat=80
 mavis/mavis.h         |  48 ++++++++++++-
 mavis/mavis_parse.c   | 184 +++++++++++++++-----------------------------------
 tac_plus-ng/config.c  | 151 ++++++++++-------------------------------
 tac_plus-ng/headers.h |   8 +--
 tac_plus/config.c     | 169 ++++++++++++++++++----------------------------
 5 files changed, 203 insertions(+), 357 deletions(-)

Answer 1 · 2023-06-16T14:22:39.000Z

Hi,

thanks -- could you please check whether a92d7f8 fixes this issue?

Cheers,

Marc

Answer 2 · 2023-06-16T18:55:07.000Z

Hi,

unfortunately not:

12: 20:29:54.006 0/c8d5f74a: 9.8.7.6 authen: hdr->seq_no: 3
12: 20:29:54.006 0/c8d5f74a: 9.8.7.6 looking for user test@MYDOMAIN realm default
12: 20:29:54.006 0/c8d5f74a: 9.8.7.6 user lookup failed
0/line 56: [!] => true
0/line 56: [skip]
0/line 58: [<unknown>] $TYPE = 'TACPLUS' => true
0/line 59: [<unknown>] $TACTYPE = 'AUTH' => true
0/line 59: [attribute] $PASSWORD = '$DBPASSWORD' => false
0/line 59: [&&] => false
0/line 59: [<unknown>] $TACTYPE = 'INFO' => false
0/line 59: [||] => false
12: 20:29:54.086 0/c8d5f74a: 9.8.7.6 looking for user test@MYDOMAIN realm default
12: 20:29:54.086 0/c8d5f74a: 9.8.7.6 user lookup failed
12: 20:29:54.086 0/c8d5f74a: 9.8.7.6 shell login for 'test@MYDOMAIN' from 1.2.3.4 on tty10 failed (no such user)
12: 20:29:54.086 0/c8d5f74a: 9.8.7.6 Writing AUTHEN/FAIL size=86

I guess the failing password comparison is the problem here.
But for some reason the matching seems to work in d2f48d7 (the debug logging in this version does not tell anything about the matchings from the if-block).

Answer 3 · 2023-06-16T21:15:56.000Z

Hi,

could you please rebuild with "configure --debug" and retry? That might give a clue.

Thanks,

Marc

Answer 4 · 2023-06-18T11:34:53.000Z

Hi,

am I expected to see more information in debug logging with level 1023 and configure --debug?

Here is the full masked debug log for the failing login request (which does not seem to have more information than without configure --debug):

12: 13:11:44.470 0/00000000: - cidr match level 1 = ***
12: 13:11:44.470 0/00000000: - cidr match level 0 = DEFAULT
12: 13:11:44.470 0/00000000: - connection request from *.*.*.*
12: 13:11:44.470 0/1b0ff03c: *.*.*.* New session
12: 13:11:44.470 0/1b0ff03c: *.*.*.* ---<start packet>---
12: 13:11:44.470 0/1b0ff03c: *.*.*.* key used: cisco
12: 13:11:44.470 0/1b0ff03c: *.*.*.* version: 192, type: 1, seq no: 1, flags: unencrypted
12: 13:11:44.470 0/1b0ff03c: *.*.*.* session id: 3cf00f1b, data length: 38
12: 13:11:44.470 0/1b0ff03c: *.*.*.* packet body (len: 38): \001\001\001\001\f\005\r\000test@MYDOMAINtty*.*.*.*
12: 13:11:44.470 0/1b0ff03c: *.*.*.* 0000 01 01 01 01 0c 05 0d 00  74 65 73 74 40 64 61 69  ........ test@***
12: 13:11:44.470 0/1b0ff03c: *.*.*.* 0010 6d 6c 65 72 74 74 79 31  31 38 32 2e 32 31 30 2e  ****tty1 *.*.*.*
12: 13:11:44.470 0/1b0ff03c: *.*.*.* AUTHEN/START, priv_lvl=1
12: 13:11:44.470 0/1b0ff03c: *.*.*.* action=login (1)
12: 13:11:44.470 0/1b0ff03c: *.*.*.* authen_type=ascii (1)
12: 13:11:44.470 0/1b0ff03c: *.*.*.* service=login (1)
12: 13:11:44.470 0/1b0ff03c: *.*.*.* user_len=12 port_len=5 rem_addr_len=13
12: 13:11:44.470 0/1b0ff03c: *.*.*.* data_len=0
12: 13:11:44.470 0/1b0ff03c: *.*.*.* user (len: 12): test@MYDOMAIN
12: 13:11:44.470 0/1b0ff03c: *.*.*.* port (len: 5): tty11
12: 13:11:44.470 0/1b0ff03c: *.*.*.* rem_addr (len: 13): *.*.*.*
12: 13:11:44.470 0/1b0ff03c: *.*.*.* ---<end packet>---
12: 13:11:44.470 0/1b0ff03c: *.*.*.* authen: hdr->seq_no: 1
12: 13:11:44.470 0/1b0ff03c: *.*.*.* looking for user test@MYDOMAIN realm default
12: 13:11:44.470 0/1b0ff03c: *.*.*.* user lookup failed
12: 13:11:44.470 0/1b0ff03c: *.*.*.* Writing AUTHEN/GETPASS size=29
12: 13:11:44.470 0/1b0ff03c: *.*.*.* ---<start packet>---
12: 13:11:44.470 0/1b0ff03c: *.*.*.* key used: cisco
12: 13:11:44.470 0/1b0ff03c: *.*.*.* version: 192, type: 1, seq no: 2, flags: unencrypted
12: 13:11:44.470 0/1b0ff03c: *.*.*.* session id: 3cf00f1b, data length: 17
12: 13:11:44.470 0/1b0ff03c: *.*.*.* packet body (len: 17): \005\001\000\v\000\000\nPassword:
12: 13:11:44.470 0/1b0ff03c: *.*.*.* 0000 05 01 00 0b 00 00 0a 50  61 73 73 77 6f 72 64 3a  .......P assword:
12: 13:11:44.470 0/1b0ff03c: *.*.*.* 0010 20
12: 13:11:44.470 0/1b0ff03c: *.*.*.* AUTHEN, status=5 (AUTHEN/GETPASS) flags=0x1
12: 13:11:44.470 0/1b0ff03c: *.*.*.* msg_len=11, data_len=0
12: 13:11:44.470 0/1b0ff03c: *.*.*.* msg (len: 11): \nPassword:
12: 13:11:44.470 0/1b0ff03c: *.*.*.* data (len: 0):
12: 13:11:44.470 0/1b0ff03c: *.*.*.* ---<end packet>---
12: 13:11:44.477 0/1b0ff03c: *.*.*.* ---<start packet>---
12: 13:11:44.477 0/1b0ff03c: *.*.*.* key used: cisco
12: 13:11:44.477 0/1b0ff03c: *.*.*.* version: 192, type: 1, seq no: 3, flags: unencrypted
12: 13:11:44.477 0/1b0ff03c: *.*.*.* session id: 3cf00f1b, data length: 6
12: 13:11:44.477 0/1b0ff03c: *.*.*.* packet body [partially masked] (len: 6): \000\001\000\000\000*
12: 13:11:44.477 0/1b0ff03c: *.*.*.* 0000 00 01 00 00 00 2a                                 .....*
12: 13:11:44.477 0/1b0ff03c: *.*.*.* AUTHEN/CONT user_msg_len=1, user_data_len=0
12: 13:11:44.477 0/1b0ff03c: *.*.*.* ---<end packet>---
12: 13:11:44.477 0/1b0ff03c: *.*.*.* authen: hdr->seq_no: 3
12: 13:11:44.477 0/1b0ff03c: *.*.*.* looking for user test@MYDOMAIN realm default
12: 13:11:44.477 0/1b0ff03c: *.*.*.* user lookup failed
0/line 56: [!] => true
0/line 56: [skip]
0/line 58: [<unknown>] $TYPE = 'TACPLUS' => true
0/line 59: [<unknown>] $TACTYPE = 'AUTH' => true
0/line 59: [attribute] $PASSWORD = '$DBPASSWORD' => false
0/line 59: [&&] => false
0/line 59: [<unknown>] $TACTYPE = 'INFO' => false
0/line 59: [||] => false
12: 13:11:44.550 0/1b0ff03c: *.*.*.* looking for user test@MYDOMAIN realm default
12: 13:11:44.550 0/1b0ff03c: *.*.*.* user lookup failed
12: 13:11:44.550 0/1b0ff03c: *.*.*.* shell login for 'test@MYDOMAIN' from *.*.*.* on tty11 failed (no such user)
12: 13:11:44.550 0/1b0ff03c: *.*.*.* Writing AUTHEN/FAIL size=86
12: 13:11:44.550 0/1b0ff03c: *.*.*.* ---<start packet>---
12: 13:11:44.550 0/1b0ff03c: *.*.*.* key used: cisco
12: 13:11:44.550 0/1b0ff03c: *.*.*.* version: 192, type: 1, seq no: 4, flags: unencrypted
12: 13:11:44.550 0/1b0ff03c: *.*.*.* session id: 3cf00f1b, data length: 74
12: 13:11:44.550 0/1b0ff03c: *.*.*.* packet body (len: 74): \002\000\000D\000\000Password incorrect.\n\nPassword incorrect -OR- insufficient privileges
12: 13:11:44.550 0/1b0ff03c: *.*.*.* 0000 02 00 00 44 00 00 50 61  73 73 77 6f 72 64 20 69  ...D..Pa ssword i
12: 13:11:44.550 0/1b0ff03c: *.*.*.* 0010 6e 63 6f 72 72 65 63 74  2e 0a 0a 50 61 73 73 77  ncorrect ...Passw
12: 13:11:44.550 0/1b0ff03c: *.*.*.* 0020 6f 72 64 20 69 6e 63 6f  72 72 65 63 74 20 2d 4f  ord inco rrect -O
12: 13:11:44.550 0/1b0ff03c: *.*.*.* 0030 52 2d 20 69 6e 73 75 66  66 69 63 69 65 6e 74 20  R- insuf ficient
12: 13:11:44.550 0/1b0ff03c: *.*.*.* 0040 70 72 69 76 69 6c 65 67  65 73                    privileg es
12: 13:11:44.550 0/1b0ff03c: *.*.*.* AUTHEN, status=2 (AUTHEN/FAIL) flags=0x0
12: 13:11:44.550 0/1b0ff03c: *.*.*.* msg_len=68, data_len=0
12: 13:11:44.550 0/1b0ff03c: *.*.*.* msg (len: 68): Password incorrect.\n\nPassword incorrect -OR- insufficient privileges
12: 13:11:44.550 0/1b0ff03c: *.*.*.* data (len: 0):
12: 13:11:44.550 0/1b0ff03c: *.*.*.* ---<end packet>---
2023-06-18 13:11:44 +0200       *.*.*.*     test@MYDOMAIN    tty11   *.*.*.*   shell login failed (no such user)

For comparision the full masked debug log with d2f48d7 (and configure --debug and debug = 1023).
The failing login is expected due to wrong credentials. But the authentication does not break with '(uknown user)' and sends the expected request to the radius server.
It is also lacking the line parsing information:

12: 13:26:40.939 0/00000000: - cidr match level 1 = zzx
12: 13:26:40.939 0/00000000: - cidr match level 0 = DEFAULT
12: 13:26:40.939 0/00000000: - connection request from *.*.*.*
12: 13:26:40.939 0/14d869ec: *.*.*.* New session
12: 13:26:40.939 0/14d869ec: *.*.*.* ---<start packet>---
12: 13:26:40.939 0/14d869ec: *.*.*.* key used: cisco
12: 13:26:40.939 0/14d869ec: *.*.*.* version: 192, type: 1, seq no: 1, flags: unencrypted
12: 13:26:40.939 0/14d869ec: *.*.*.* session id: ec69d814, data length: 38
12: 13:26:40.939 0/14d869ec: *.*.*.* packet body (len: 38): \001\001\001\001\f\005\r\000test@MYDOMAINtty*.*.*.*
12: 13:26:40.939 0/14d869ec: *.*.*.* 0000 01 01 01 01 0c 05 0d 00  74 65 73 74 40 64 61 69  ........ test@***
12: 13:26:40.939 0/14d869ec: *.*.*.* 0010 6d 6c 65 72 74 74 79 31  30 38 32 2e 32 31 30 2e  ****tty1 082.210.
12: 13:26:40.939 0/14d869ec: *.*.*.* 0020 32 30 34 2e 34 35                                 204.45
12: 13:26:40.939 0/14d869ec: *.*.*.* AUTHEN/START, priv_lvl=1
12: 13:26:40.939 0/14d869ec: *.*.*.* action=login (1)
12: 13:26:40.939 0/14d869ec: *.*.*.* authen_type=ascii (1)
12: 13:26:40.939 0/14d869ec: *.*.*.* service=login (1)
12: 13:26:40.939 0/14d869ec: *.*.*.* user_len=12 port_len=5 rem_addr_len=13
12: 13:26:40.939 0/14d869ec: *.*.*.* data_len=0
12: 13:26:40.939 0/14d869ec: *.*.*.* user (len: 12): test@MYDOMAIN
12: 13:26:40.939 0/14d869ec: *.*.*.* 0000 74 65 73 74 40 64 61 69  6d 6c 65 72              test@MYDOMAIN
12: 13:26:40.939 0/14d869ec: *.*.*.* port (len: 5): tty10
12: 13:26:40.939 0/14d869ec: *.*.*.* 0000 74 74 79 31 30                                    tty10
12: 13:26:40.939 0/14d869ec: *.*.*.* rem_addr (len: 13): *.*.*.*
12: 13:26:40.939 0/14d869ec: *.*.*.* 0000 38 32 2e 32 31 30 2e 32  30 34 2e 34 35           *.*.*.*
12: 13:26:40.939 0/14d869ec: *.*.*.* ---<end packet>---
12: 13:26:40.939 0/14d869ec: *.*.*.* authen: hdr->seq_no: 1
12: 13:26:40.939 0/14d869ec: *.*.*.* looking for user test@MYDOMAIN realm default
12: 13:26:40.939 0/14d869ec: *.*.*.* user lookup failed
12: 13:26:40.939 0/14d869ec: *.*.*.* Writing AUTHEN/GETPASS size=29
12: 13:26:40.939 0/14d869ec: *.*.*.* ---<start packet>---
12: 13:26:40.939 0/14d869ec: *.*.*.* key used: cisco
12: 13:26:40.939 0/14d869ec: *.*.*.* version: 192, type: 1, seq no: 2, flags: unencrypted
12: 13:26:40.939 0/14d869ec: *.*.*.* session id: ec69d814, data length: 17
12: 13:26:40.939 0/14d869ec: *.*.*.* packet body (len: 17): \005\001\000\v\000\000\nPassword:
12: 13:26:40.939 0/14d869ec: *.*.*.* 0000 05 01 00 0b 00 00 0a 50  61 73 73 77 6f 72 64 3a  .......P assword:
12: 13:26:40.939 0/14d869ec: *.*.*.* 0010 20
12: 13:26:40.939 0/14d869ec: *.*.*.* AUTHEN, status=5 (AUTHEN/GETPASS) flags=0x1
12: 13:26:40.939 0/14d869ec: *.*.*.* msg_len=11, data_len=0
12: 13:26:40.939 0/14d869ec: *.*.*.* msg (len: 11): \nPassword:
12: 13:26:40.939 0/14d869ec: *.*.*.* 0000 0a 50 61 73 73 77 6f 72  64 3a 20                 .Passwor d:
12: 13:26:40.939 0/14d869ec: *.*.*.* data (len: 0):
12: 13:26:40.939 0/14d869ec: *.*.*.* ---<end packet>---
12: 13:26:40.945 0/14d869ec: *.*.*.* ---<start packet>---
12: 13:26:40.945 0/14d869ec: *.*.*.* key used: cisco
12: 13:26:40.945 0/14d869ec: *.*.*.* version: 192, type: 1, seq no: 3, flags: unencrypted
12: 13:26:40.945 0/14d869ec: *.*.*.* session id: ec69d814, data length: 6
12: 13:26:40.945 0/14d869ec: *.*.*.* packet body [partially masked] (len: 6): \000\001\000\000\000*
12: 13:26:40.945 0/14d869ec: *.*.*.* 0000 00 01 00 00 00 2a                                 .....*
12: 13:26:40.945 0/14d869ec: *.*.*.* AUTHEN/CONT user_msg_len=1, user_data_len=0
12: 13:26:40.945 0/14d869ec: *.*.*.* ---<end packet>---
12: 13:26:40.945 0/14d869ec: *.*.*.* authen: hdr->seq_no: 3
12: 13:26:40.945 0/14d869ec: *.*.*.* looking for user test@MYDOMAIN realm default
12: 13:26:40.945 0/14d869ec: *.*.*.* user lookup failed
12: 13:26:40.956 0/14d869ec: *.*.*.* looking for user test@MYDOMAIN realm default
12: 13:26:40.956 0/14d869ec: *.*.*.* user lookup failed
12: 13:26:40.956 0/14d869ec: *.*.*.* shell login for 'test@MYDOMAIN' from *.*.*.* on tty10 failed
12: 13:26:40.956 0/14d869ec: *.*.*.* Writing AUTHEN/FAIL size=86
12: 13:26:40.956 0/14d869ec: *.*.*.* ---<start packet>---
12: 13:26:40.956 0/14d869ec: *.*.*.* key used: cisco
12: 13:26:40.956 0/14d869ec: *.*.*.* version: 192, type: 1, seq no: 4, flags: unencrypted
12: 13:26:40.956 0/14d869ec: *.*.*.* session id: ec69d814, data length: 74
12: 13:26:40.956 0/14d869ec: *.*.*.* packet body (len: 74): \002\000\000D\000\000Password incorrect.\n\nPassword incorrect -OR- insufficient privileges
12: 13:26:40.956 0/14d869ec: *.*.*.* 0000 02 00 00 44 00 00 50 61  73 73 77 6f 72 64 20 69  ...D..Pa ssword i
12: 13:26:40.956 0/14d869ec: *.*.*.* 0010 6e 63 6f 72 72 65 63 74  2e 0a 0a 50 61 73 73 77  ncorrect ...Passw
12: 13:26:40.956 0/14d869ec: *.*.*.* 0020 6f 72 64 20 69 6e 63 6f  72 72 65 63 74 20 2d 4f  ord inco rrect -O
12: 13:26:40.956 0/14d869ec: *.*.*.* 0030 52 2d 20 69 6e 73 75 66  66 69 63 69 65 6e 74 20  R- insuf ficient
12: 13:26:40.956 0/14d869ec: *.*.*.* 0040 70 72 69 76 69 6c 65 67  65 73                    privileg es
12: 13:26:40.956 0/14d869ec: *.*.*.* AUTHEN, status=2 (AUTHEN/FAIL) flags=0x0
12: 13:26:40.956 0/14d869ec: *.*.*.* msg_len=68, data_len=0
12: 13:26:40.956 0/14d869ec: *.*.*.* msg (len: 68): Password incorrect.\n\nPassword incorrect -OR- insufficient privileges
12: 13:26:40.956 0/14d869ec: *.*.*.* 0000 50 61 73 73 77 6f 72 64  20 69 6e 63 6f 72 72 65  Password  incorre
12: 13:26:40.956 0/14d869ec: *.*.*.* 0010 63 74 2e 0a 0a 50 61 73  73 77 6f 72 64 20 69 6e  ct...Pas sword in
12: 13:26:40.956 0/14d869ec: *.*.*.* 0020 63 6f 72 72 65 63 74 20  2d 4f 52 2d 20 69 6e 73  correct  -OR- ins
12: 13:26:40.956 0/14d869ec: *.*.*.* 0030 75 66 66 69 63 69 65 6e  74 20 70 72 69 76 69 6c  ufficien t privil
12: 13:26:40.956 0/14d869ec: *.*.*.* 0040 65 67 65 73                                       eges
12: 13:26:40.956 0/14d869ec: *.*.*.* data (len: 0):
12: 13:26:40.956 0/14d869ec: *.*.*.* ---<end packet>---
2023-06-18 13:26:40 +0200       *.*.*.*     test@MYDOMAIN    tty10   *.*.*.*   shell login failed

Build process snippets:

...
./configure --debug --with-pcre --with-freeradius tac_plus
...
#8 42.06 make[1]: Entering directory '/tmp/event-driven-servers/mavis'
#8 42.08 make[2]: Entering directory '/tmp/event-driven-servers/build/linux-5.15.0-73-generic-x86_64/mavis'
#8 42.09 gcc  -Wall -W -Wno-strict-prototypes -Wno-implicit-fallthrough -Werror -Wno-deprecated-declarations -Wno-unused-result -g -Og -ggdb  -DOSTYPE=linux -DOSLEVEL=0x050f0000 -DOS="\"linux-5.15.0-73-generic-x86_64\"" -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -DDEBUG -DWITH_PCRE -DWITH_FREERADIUS -DWITH_CRYPT -DWITH_EPOLL -DWITH_POLL -DWITH_SELECT -DWITH_IPC -I/tmp/event-driven-servers -I/usr/include      -fPIC -c -o libmavis.o /tmp/event-driven-servers/mavis/libmavis.c
#8 42.22 gcc  -Wall -W -Wno-strict-prototypes -Wno-implicit-fallthrough -Werror -Wno-deprecated-declarations -Wno-unused-result -g -Og -ggdb  -DOSTYPE=linux -DOSLEVEL=0x050f0000 -DOS="\"linux-5.15.0-73-generic-x86_64\"" -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -DDEBUG -DWITH_PCRE -DWITH_FREERADIUS -DWITH_CRYPT -DWITH_EPOLL -DWITH_POLL -DWITH_SELECT -DWITH_IPC -I/tmp/event-driven-servers -I/usr/include      -fPIC -c -o log.o /tmp/event-driven-servers/mavis/log.c
#8 42.29 gcc  -Wall -W -Wno-strict-prototypes -Wno-implicit-fallthrough -Werror -Wno-deprecated-declarations -Wno-unused-result -g -Og -ggdb  -DOSTYPE=linux -DOSLEVEL=0x050f0000 -DOS="\"linux-5.15.0-73-generic-x86_64\"" -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -DDEBUG -DWITH_PCRE -DWITH_FREERADIUS -DWITH_CRYPT -DWITH_EPOLL -DWITH_POLL -DWITH_SELECT -DWITH_IPC -I/tmp/event-driven-servers -I/usr/include      -fPIC -c -o debug.o /tmp/event-driven-servers/mavis/debug.c
#8 42.36 gcc  -Wall -W -Wno-strict-prototypes -Wno-implicit-fallthrough -Werror -Wno-deprecated-declarations -Wno-unused-result -g -Og -ggdb  -DOSTYPE=linux -DOSLEVEL=0x050f0000 -DOS="\"linux-5.15.0-73-generic-x86_64\"" -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -DDEBUG -DWITH_PCRE -DWITH_FREERADIUS -DWITH_CRYPT -DWITH_EPOLL -DWITH_POLL -DWITH_SELECT -DWITH_IPC -I/tmp/event-driven-servers -I/usr/include      -fPIC -c -o blowfish.o /tmp/event-driven-servers/mavis/blowfish.c
#8 42.44 gcc  -Wall -W -Wno-strict-prototypes -Wno-implicit-fallthrough -Werror -Wno-deprecated-declarations -Wno-unused-result -g -Og -ggdb  -DOSTYPE=linux -DOSLEVEL=0x050f0000 -DOS="\"linux-5.15.0-73-generic-x86_64\"" -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -DDEBUG -DWITH_PCRE -DWITH_FREERADIUS -DWITH_CRYPT -DWITH_EPOLL -DWITH_POLL -DWITH_SELECT -DWITH_IPC -I/tmp/event-driven-servers -I/usr/include      -fPIC -c -o radix.o /tmp/event-driven-servers/misc/radix.c
...

Answer 5 · 2023-06-18T12:46:16.000Z

Hi,

did you run "make install" after "configure --debug" and make? There's no MAVIS debug output, so you've likely run your tests with the binaries from a previous compile.

Do your latest tests cover your initial issue which I think is resolved with a92d7f8? You did test with wrong credentials but with the @MYDOMAIN domain suffix, so "script in" won't skip the module. Next, "radmavis" tries to validate the credentials and fails, and finally "script out" fails too (radmavis will set the DBPASSWORD variable only if authentication succeeds). Looks like expected behavior to me.

Also, radmavis will set the RESULT variable if authentication succeeds, so there's no need to do that manually. I'd shorten the module configuration to:

        mavis module = external {
                script in  = { if ($USER !~ /^.*\@MYDOMAIN.*$/ ) skip }
                script out = {
                        if (($TYPE == TACPLUS) && ($USER =~ /^.*\@MYDOMAIN.*$/ )) {
                                if ($TACTYPE == INFO) # No authorization support for RADIUS
                                        set $RESULT = ACK
                                set $TACMEMBER = "MYDOMAIN_GROUP"
                        }
                }
                exec = /usr/local/sbin/radmavis radmavis "authserver=1.2.3.4:5678:mysecret"
        }

Cheers,

Marc

Answer 6 · 2023-06-18T13:47:28.000Z

Hi,

yes, the binares were compiled. The application as well as the building process are wrapped into CI/CD with docker. My manual building is also being done with --no-cache.
The tac_plus binary also claims to be from the latest commit id:

$ tac_plus -v
tac_plus version dea6f7ce8f2f48e076d610e90be6157196477c14/PCRE (deprecated)

Unfortunately I currently do not have a valid testing account for the external radius authentication. But regular users as well as my invalid credential testing with the desired domain do result in the same failing behaviour, that the tac_plus log states a "(no such user)" error and there is no package being sent to the radius server. So tac_plus can't even have tried to query the radius with the authentication request in this case (where the application version from the working commit does so).

The credentials failing in my tests is not the point of issue- it is the "(no such user)" part and missing radius authentication request what seems to be an issue with invalid as well as valid credentials.

With you config adjustment suggestion the debug log looks like this (again without any communication attempt to the radius server):

14: 15:42:43.584 6/00000000: - cidr match level 1 = ***
14: 15:42:43.584 6/00000000: - cidr match level 0 = DEFAULT
14: 15:42:43.584 6/00000000: - connection request from *.*.*.*
14: 15:42:43.585 6/65ba47d4: *.*.*.* New session
14: 15:42:43.585 6/65ba47d4: *.*.*.* ---<start packet>---
14: 15:42:43.585 6/65ba47d4: *.*.*.* key used: cisco
14: 15:42:43.585 6/65ba47d4: *.*.*.* version: 192, type: 1, seq no: 1, flags: unencrypted
14: 15:42:43.585 6/65ba47d4: *.*.*.* session id: d447ba65, data length: 38
14: 15:42:43.585 6/65ba47d4: *.*.*.* packet body (len: 38): \001\001\001\001\f\005\r\000test@MYDOMAINtty*.*.*.*
14: 15:42:43.585 6/65ba47d4: *.*.*.* 0000 01 01 01 01 0c 05 0d 00  74 65 73 74 40 64 61 69  ........ test@***
14: 15:42:43.585 6/65ba47d4: *.*.*.* 0010 6d 6c 65 72 74 74 79 31  30 38 32 2e 32 31 30 2e  ****tty1 *.*.*.*
14: 15:42:43.585 6/65ba47d4: *.*.*.* AUTHEN/START, priv_lvl=1
14: 15:42:43.585 6/65ba47d4: *.*.*.* action=login (1)
14: 15:42:43.585 6/65ba47d4: *.*.*.* authen_type=ascii (1)
14: 15:42:43.585 6/65ba47d4: *.*.*.* service=login (1)
14: 15:42:43.585 6/65ba47d4: *.*.*.* user_len=12 port_len=5 rem_addr_len=13
14: 15:42:43.585 6/65ba47d4: *.*.*.* data_len=0
14: 15:42:43.585 6/65ba47d4: *.*.*.* user (len: 12): test@MYDOMAIN
14: 15:42:43.585 6/65ba47d4: *.*.*.* port (len: 5): tty10
14: 15:42:43.585 6/65ba47d4: *.*.*.* rem_addr (len: 13): *.*.*.*
14: 15:42:43.585 6/65ba47d4: *.*.*.* ---<end packet>---
14: 15:42:43.585 6/65ba47d4: *.*.*.* authen: hdr->seq_no: 1
14: 15:42:43.585 6/65ba47d4: *.*.*.* looking for user test@MYDOMAIN realm default
14: 15:42:43.585 6/65ba47d4: *.*.*.* user lookup failed
14: 15:42:43.585 6/65ba47d4: *.*.*.* Writing AUTHEN/GETPASS size=29
14: 15:42:43.585 6/65ba47d4: *.*.*.* ---<start packet>---
14: 15:42:43.585 6/65ba47d4: *.*.*.* key used: cisco
14: 15:42:43.585 6/65ba47d4: *.*.*.* version: 192, type: 1, seq no: 2, flags: unencrypted
14: 15:42:43.585 6/65ba47d4: *.*.*.* session id: d447ba65, data length: 17
14: 15:42:43.585 6/65ba47d4: *.*.*.* packet body (len: 17): \005\001\000\v\000\000\nPassword:
14: 15:42:43.585 6/65ba47d4: *.*.*.* 0000 05 01 00 0b 00 00 0a 50  61 73 73 77 6f 72 64 3a  .......P assword:
14: 15:42:43.585 6/65ba47d4: *.*.*.* 0010 20
14: 15:42:43.585 6/65ba47d4: *.*.*.* AUTHEN, status=5 (AUTHEN/GETPASS) flags=0x1
14: 15:42:43.585 6/65ba47d4: *.*.*.* msg_len=11, data_len=0
14: 15:42:43.585 6/65ba47d4: *.*.*.* msg (len: 11): \nPassword:
14: 15:42:43.585 6/65ba47d4: *.*.*.* data (len: 0):
14: 15:42:43.585 6/65ba47d4: *.*.*.* ---<end packet>---
14: 15:42:44.426 6/65ba47d4: *.*.*.* ---<start packet>---
14: 15:42:44.426 6/65ba47d4: *.*.*.* key used: cisco
14: 15:42:44.426 6/65ba47d4: *.*.*.* version: 192, type: 1, seq no: 3, flags: unencrypted
14: 15:42:44.426 6/65ba47d4: *.*.*.* session id: d447ba65, data length: 6
14: 15:42:44.426 6/65ba47d4: *.*.*.* packet body [partially masked] (len: 6): \000\001\000\000\000*
14: 15:42:44.426 6/65ba47d4: *.*.*.* 0000 00 01 00 00 00 2a                                 .....*
14: 15:42:44.426 6/65ba47d4: *.*.*.* AUTHEN/CONT user_msg_len=1, user_data_len=0
14: 15:42:44.426 6/65ba47d4: *.*.*.* ---<end packet>---
14: 15:42:44.426 6/65ba47d4: *.*.*.* authen: hdr->seq_no: 3
14: 15:42:44.426 6/65ba47d4: *.*.*.* looking for user test@MYDOMAIN realm default
14: 15:42:44.426 6/65ba47d4: *.*.*.* user lookup failed
0/line 70: [!] => true
0/line 70: [skip]
0/line 72: [<unknown>] $TYPE = 'TACPLUS' => true
0/line 72: [&&] => false
14: 15:42:44.511 6/65ba47d4: *.*.*.* looking for user test@MYDOMAIN realm default
14: 15:42:44.511 6/65ba47d4: *.*.*.* user lookup failed
14: 15:42:44.511 6/65ba47d4: *.*.*.* shell login for 'test@MYDOMAIN' from *.*.*.* on tty10 failed (no such user)
14: 15:42:44.511 6/65ba47d4: *.*.*.* Writing AUTHEN/FAIL size=86
14: 15:42:44.511 6/65ba47d4: *.*.*.* ---<start packet>---
14: 15:42:44.511 6/65ba47d4: *.*.*.* key used: cisco
14: 15:42:44.511 6/65ba47d4: *.*.*.* version: 192, type: 1, seq no: 4, flags: unencrypted
14: 15:42:44.511 6/65ba47d4: *.*.*.* session id: d447ba65, data length: 74
14: 15:42:44.511 6/65ba47d4: *.*.*.* packet body (len: 74): \002\000\000D\000\000Password incorrect.\n\nPassword incorrect -OR- insufficient privileges
14: 15:42:44.511 6/65ba47d4: *.*.*.* 0000 02 00 00 44 00 00 50 61  73 73 77 6f 72 64 20 69  ...D..Pa ssword i
14: 15:42:44.511 6/65ba47d4: *.*.*.* 0010 6e 63 6f 72 72 65 63 74  2e 0a 0a 50 61 73 73 77  ncorrect ...Passw
14: 15:42:44.511 6/65ba47d4: *.*.*.* 0020 6f 72 64 20 69 6e 63 6f  72 72 65 63 74 20 2d 4f  ord inco rrect -O
14: 15:42:44.511 6/65ba47d4: *.*.*.* 0030 52 2d 20 69 6e 73 75 66  66 69 63 69 65 6e 74 20  R- insuf ficient
14: 15:42:44.511 6/65ba47d4: *.*.*.* 0040 70 72 69 76 69 6c 65 67  65 73                    privileg es
14: 15:42:44.511 6/65ba47d4: *.*.*.* AUTHEN, status=2 (AUTHEN/FAIL) flags=0x0
14: 15:42:44.511 6/65ba47d4: *.*.*.* msg_len=68, data_len=0
14: 15:42:44.511 6/65ba47d4: *.*.*.* msg (len: 68): Password incorrect.\n\nPassword incorrect -OR- insufficient privileges
14: 15:42:44.511 6/65ba47d4: *.*.*.* data (len: 0):
14: 15:42:44.511 6/65ba47d4: *.*.*.* ---<end packet>---
2023-06-18 15:42:44 +0200       *.*.*.*     test@MYDOMAIN    tty10   *.*.*.*   shell login failed (no such user)

Answer 7 · 2023-06-18T14:32:16.000Z

Hi,

please retry with "debug = -1", I've missed your "debug = 1023" part.

Cheers,

Marc

Answer 8 · 2023-06-18T15:02:26.000Z

Hi,

yeah - I could have also tried to raise the level. I thought the extended decryption stuff would probably not be relevant.

tac_plus.log

Answer 9 · 2023-06-18T15:56:04.000Z

Hi,

your log shows a failed LDAP query for test@MYDOMAIN, followed by "shell login failed (no such user)", and a cached "shell login failed (no such user)" afterwards.

That has nothing at all in common with your initial issue with RADIUS authentication and evaluation of variables.

Please open an issue that clearly details your configuration, the problem you think you're seeing and debug logs that cover your use case.

Cheers,

Marc