Exec-Program-Wait not working

[Gianni Costanzi]

On Wed, Jun 19, 2019 at 5:27 PM Alan DeKok <aland at deployingradius.com>
wrote:

> On Jun 19, 2019, at 11:16 AM, Gianni Costanzi <gianni.costanzi at gmail.com>
> wrote:
> > I was using the following syntax on Freeradius 2.x to determine if a user
> > could connect to a particular IP address, even if the authentication
> > succeeds, based on some parameters passed to a script:
> >
> > XXX747 Auth-Type = System, Realm == imp
> >        Service-Type := Login-User,
> >        cisco-avpair = "shell:priv-lvl=2",
> >        Exec-Program-Wait =
> > "/opt/script/radius/bin/check_operator_access.sh %{NAS-IP-Address}
> > %{User-Name} %{Realm}"
>
>   Exec-Program-Wait goes in the first line.  It's a check attribute, and
> isn't a reply attribute.
>
>   Alan DeKok.
>
>
I tried to move the Exec-Program-Wait to the first line but it is still not
executed.. I can see that the authentication is proxied to realm Imp, it
receives an Access accept but then
the entry or XXX747 is not matched and the DEFAULT entry with an access
Reject is matched. The program is still not executed:

XXX747 Auth-Type = System, Realm == imp, Exec-Program-Wait =
"/opt/script/radius/bin/check_operator_access.sh %{NAS-IP-Address}
%{User-Name} %{Realm}"
        Service-Type := Login-User,
        cisco-avpair = "shell:priv-lvl=2"

Is the above entry correct, with Exec-Program-Wait on the first line?

Some logs:

(3) suffix: Proxying request from user XXX747 to realm imp
(3) suffix: Preparing to proxy authentication request to realm "imp"
(3)     [suffix] = updated
(3) files: EXPAND /opt/script/radius/bin/check_operator_access.sh
%{NAS-IP-Address} %{User-Name} %{Realm}
(3) files:    --> /opt/script/radius/bin/check_operator_access.sh
10.227.143.200 XXX747 at imp imp
(3) files: users: Matched entry DEFAULT at line 17805
(3)     [files] = ok
(3) sql: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-none}}
(3) sql:    --> XXX747
(3) sql: SQL-User-Name set to 'XXX747'
rlm_sql (sql): Reserved connection (3)
(3) sql: EXPAND SELECT id, UserName, Attribute, Value, Op FROM radcheck
WHERE Username = '%{SQL-User-Name}' ORDER BY id
(3) sql:    --> SELECT id, UserName, Attribute, Value, Op FROM radcheck
WHERE Username = 'XXX747' ORDER BY id
(3) sql: Executing select query: SELECT id, UserName, Attribute, Value, Op
FROM radcheck WHERE Username = 'XXX747' ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 0 , fields = 5
(3) sql: EXPAND SELECT GroupName FROM radusergroup WHERE
UserName='%{SQL-User-Name}' ORDER BY priority
(3) sql:    --> SELECT GroupName FROM radusergroup WHERE UserName='XXX747'
ORDER BY priority
(3) sql: Executing select query: SELECT GroupName FROM radusergroup WHERE
UserName='XXX747' ORDER BY priority
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 0 , fields = 1
(3) sql: User not found in any groups
rlm_sql (sql): Released connection (3)
Need 3 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (7), 1 of 25 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname='radius_db'
host='127.0.0.1' port=5432 user='radius' password='cPKlc-Pb_H09'
application_name='FreeRADIUS 3.0.13 - radiusd (sql)'
Connected to database 'radius_db' on '127.0.0.1' server version 90224,
protocol version 3, backend PID 968
(3)     [sql] = notfound
(3)     [expiration] = noop
(3)     [logintime] = noop
(3)     [pap] = noop
(3)   } # authorize = updated
(3) Starting proxy to home server 10.240.24.151 port 1812
(3) Proxying request to home server 10.240.24.151 port 1812 timeout
20.000000
(3) Sent Access-Request Id 126 from 0.0.0.0:34919 to 10.240.24.151:1812
length 101
(3)   User-Name := "XXX747"
(3)   User-Password = "1234567890"
(3)   NAS-Port = 132
(3)   NAS-Port-Id = "tty132"
(3)   NAS-Port-Type = Virtual
(3)   NAS-IP-Address = 10.227.143.200
(3)   Event-Timestamp = "Jun 19 2019 17:51:56 CEST"
(3)   Message-Authenticator := 0x00
(3)   Proxy-State = 0x313438
Waking up in 0.3 seconds.
(3) Clearing existing &reply: attributes
(3) Received Access-Accept Id 126 from 10.240.24.151:1812 to
10.240.0.5:34919 length 49
(3)   Reply-Message = "Pass"
(3)   Message-Authenticator = 0x4e57018f18713865960677d6ccf7002b
(3)   Proxy-State = 0x313438
(3) # Executing section post-proxy from file
/etc/raddb/sites-enabled/default
(3)   post-proxy {
(3) attr_filter.post-proxy: EXPAND %{Realm}
(3) attr_filter.post-proxy:    --> imp
(3) attr_filter.post-proxy: Matched entry imp at line 110
(3)     [attr_filter.post-proxy] = updated
(3)   } # post-proxy = updated
(3) Found Auth-Type = Reject
(3) Auth-Type = Reject, rejecting user
(3) Failed to authenticate the user
(3) Login incorrect: [XXX747 at imp] (from client r-AA port 132)
(3) Using Post-Auth-Type Reject