Some RLM_MODULE_INVALID events are not logged via detail

[Alan DeKok]

On Oct 30, 2019, at 12:47 PM, Boris Lytochkin <lytboris at yandex-team.ru> wrote:
> 
> We're trying to catch a bug in some vendor's equipment resulting in
> "Login incorrect (eap: EAP requires the State attribute to work, but no State exists in the Access-Request packet.)"

  Well that's unfortunate.  It's also a pretty darned serious bug.

> 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.

>                 }
>         ...
>     }
> ==================
> 
> 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.

> p/s. Playing around with `handled` in Auth-Type EAP has nothing to do with detailed log as I see the same situation before I tweaked that part of the configuration.
> 
> 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.

  Alan DeKok.