Re: Some RLM_MODULE_INVALID events are not logged via detail

30 Oct 2019

      Hi.

See inline.

On 30.10.2019 19:58, Alan DeKok wrote:
...
On Oct 30, 2019, at 12:47 PM, Boris Lytochkin <lytboris@yandex-team.ru> wrote:
...
error appearing in the log and subsequent Access-Reject sent from RADIUS server (version 3.0.15 with a bit of pull requests still not merged :).
It seems that this configuration does not catch that particular Access-Reject into detail(ed) log:
==================
         detail auth_log {
                 header = "%t (%I)"
                 filename = ${radacctdir}/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-%Y%m%d
                 log_packet_header = yes
                 permissions = 0640
         }
authenticate {
                 Auth-Type EAP {
                         eap {
                                 handled = 9999
                         }
                         if (handled) {
                                 auth_log.post-auth
                                 # logging is done, return
                                 return
                         }
                         # eap module returned OK so we go a bit further
                         perl
                         # Access-Accept/Reject will be logged by authorize section
   The reject is logged by the Post-Auth section.
...
}
         }
post-auth {
                 auth_log
                 Post-Auth-Type REJECT {
                         auth_log
That should work.
But it does not for the "State" error -  packet holding Access-Reject is 
not recorded via detail.
...
...
Am I missing something? I took a quick tour though the code and failed to find a place where radiusd decides to **log**
" Login incorrect (eap_tls: TLS Alert read:fatal:unknown CA):"
into detail and **not to log**
"Login incorrect (eap: EAP requires the State attribute to work, but no State exists in the Access-Request packet.)"
   The modules add a Module-Failure-Message to the request.  When the "Login incorrect" message is logged, that function looks for Module-Failure-Message, and adds that text to the log message.
Yep, the thing is that "State" message goes into radius log but 
Access-Reject packet is not being logged into auth_log.
If you do not have any ideas why this happens I would go with further 
debugging via raddebug as we're unable to reproduce the issue in the lab 
environment.
...
...
pp/s. Is there a way to print packet identifier as it is sent over the wire into detailed log? I made a trivial patch for that seeing no documented way exist to do that:
Not really.   We can take a look at adding it.
Before I make a pull request it would be nice to know if that patch is 
good enough or I should re-write it as an attribute to be usable anywhere?
-- 
Boris Lytochkin
Yandex NOC
+7 (495) 739 70 00 ext. 7671