Server not send ACK to NAS

[as4303]

Good day!
There is a server version 3.0.13, we used rlm_ippool module.
Config:
`server fastdpi-vs {
....
accounting {

    Acct-Type Status-Server {

    }

    if (!&NAS-IP-Address) {
       update request {
        &NAS-IP-Address := "%{Packet-Src-IP-Address}"
       }
    }

    perl
    if (&Acct-Status-Type == "Start" || &Acct-Status-Type == "Stop") {
          detail
    }
    unknown_pool

}
....
`

We receive this STOP packet from NAS:

(146) Received Accounting-Request Id 201 from 10.10.1.252:34557 to 10.10.0.80:18013 length 565
(146) NAS-Identifier = "XXXX"
(146) Framed-IP-Address = xx.xx.13.144
(146) Calling-Station-Id = "00:00:00:00:96:f4"
(146) Service-Type = Framed-User
(146) User-Name = "service_2186"
(146) Acct-Session-Id = "A1F8AC1E000000E1"
(146) Acct-Authentic = RADIUS
(146) Acct-Status-Type = Stop
(146) Acct-Terminate-Cause = NAS-Request
(146) Acct-Session-Time = 1798
(146) Event-Timestamp = "авг 21 2020 13:52:25 +05"
(146) Acct-Input-Packets = 350
(146) Acct-Output-Packets = 1
(146) Acct-Input-Octets = 33757
(146) Acct-Input-Gigawords = 0
(146) Acct-Output-Octets = 113
(146) Acct-Output-Gigawords = 0
(146) # Executing section preacct from file /etc/raddb/sites-enabled/fastdpi-vs
(146) # Executing section accounting from file /etc/raddb/sites-enabled/fastdpi-vs
Tue Aug 25 12:36:26 2020 : Debug: Parsed xlat tree:
Tue Aug 25 12:36:26 2020 : Debug: attribute --> Calling-Station-Id
Tue Aug 25 12:36:26 2020 : Debug: literal --> -
Tue Aug 25 12:36:26 2020 : Debug: attribute --> NAS-Port
Tue Aug 25 12:36:26 2020 : Debug: (146) unknown_pool: EXPAND %{Calling-Station-Id}-%{NAS-Port}
Tue Aug 25 12:36:26 2020 : Debug: (146) unknown_pool: --> d4:ca:6d:3c:96:f4-
Tue Aug 25 12:36:26 2020 : Debug: (146) unknown_pool: MD5 on 'key' directive maps to: 105be0687b9e0bd834397957e8310f76
Tue Aug 25 12:36:26 2020 : Debug: (146) unknown_pool: Searching for an entry for key: 'd4:ca:6d:3c:96:f4-'
Tue Aug 25 12:36:26 2020 : Debug: (146) unknown_pool: Entry not found
Tue Aug 25 12:36:26 2020 : Debug: (146) modsingle[accounting]: returned from unknown_pool (rlm_ippool)
Tue Aug 25 12:36:26 2020 : Debug: (146) [unknown_pool] = notfound
Tue Aug 25 12:36:26 2020 : Debug: (146) } # accounting = notfound
Tue Aug 25 12:36:26 2020 : Debug: (146) Not sending reply to client.
(146) Not sending reply to client.

When a notfound response is received from the ippool module, the processing is completed and the response is not sent, and if the module responded with noop, the response is sent.
The problem was solved like this:
accounting {
unknown_pool {
notfound = 1
}
}

but its bug!

[alandekok]

RFC 2866 says that if accounting fails, then the server should not reply. So the accounting section MUST return ok in order for packets to be sent back.

just add ok at the end of the accounting section.

[NewUse]

RFC 2866 says that if accounting fails, then the server should not reply. So the accounting section MUST return ok in order for packets to be sent back.

just add ok at the end of the accounting section.

I think that "notfound" is not equal to "fail", but it seems that ippool interrupts the processing of accounting packet by other modules, is it ok?

[alandekok]

The ippool module affects how the accounting packets are handled. I don't know what you mean by "interrupts".

In any case, you already have a way to make it work. I don't think there's any bug here.

[as4303]

why do you think notfound is failing?

[alandekok]

the notfound return code is not a success return code.

[as4303]

With this configuration, we still get an error
`accounting {

Acct-Type Status-Server {

}

if (!&NAS-IP-Address) {
update request {
&NAS-IP-Address := "%{Packet-Src-IP-Address}"
}
}
perl
if (&Acct-Status-Type == "Start" || &Acct-Status-Type == "Stop") {
detail
}
unknown_pool
ok
}
`

Thu Aug 27 16:47:45 2020 : Debug: (6) unknown_pool: EXPAND %{Calling-Station-Id}
Thu Aug 27 16:47:45 2020 : Debug: (6) unknown_pool: --> 0c:ee:e6:c0:2c:e9
Thu Aug 27 16:47:45 2020 : Debug: (6) unknown_pool: MD5 on 'key' directive maps to: 853c66dfd2d607cc6121e12a86794fb1
Thu Aug 27 16:47:45 2020 : Debug: (6) unknown_pool: Searching for an entry for key: '0c:ee:e6:c0:2c:e9'
Thu Aug 27 16:47:45 2020 : Debug: (6) unknown_pool: Entry not found
Thu Aug 27 16:47:45 2020 : Debug: (6) modsingle[accounting]: returned from unknown_pool (rlm_ippool)
Thu Aug 27 16:47:45 2020 : Debug: (6) [unknown_pool] = notfound
Thu Aug 27 16:47:45 2020 : Debug: (6) } # accounting = notfound
Thu Aug 27 16:47:45 2020 : Debug: (6) Not sending reply to client.

[NewUse]

I don't know what you mean by "interrupts".

I did mean that freeradius immediately stops processing if ippool returns "notfound," as you can see above, I think it could be a bug?