Some RLM_MODULE_INVALID events are not logged via detail

[Boris Lytochkin]

And here's the answer why it is not logged:

(97599) Thu Oct 31 12:34:28 2019: Debug:   Auth-Type EAP {
(97599) Thu Oct 31 12:34:28 2019: ERROR: eap: EAP requires the State attribute to work, but no State exists in the Access-Request packet.
(97599) Thu Oct 31 12:34:28 2019: ERROR: eap: The RADIUS client is broken.  No amount of changing FreeRADIUS will fix the RADIUS client.
(97599) Thu Oct 31 12:34:28 2019: Debug: eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request
(97599) Thu Oct 31 12:34:28 2019: Debug: eap: Failed in handler
(97599) Thu Oct 31 12:34:28 2019: Debug:     [eap] = invalid
(97599) Thu Oct 31 12:34:28 2019: Debug:   } # Auth-Type EAP = invalid
(97599) Thu Oct 31 12:34:28 2019: Debug: Failed to authenticate the user
(97599) Thu Oct 31 12:34:28 2019: Debug: Using Post-Auth-Type Reject
(97599) Thu Oct 31 12:34:28 2019: Debug: # Executing group from file /usr/local/etc/raddb/radiusd.conf
(97599) Thu Oct 31 12:34:28 2019: Debug:   Post-Auth-Type REJECT {
(97599) Thu Oct 31 12:34:28 2019: Debug: auth_log: EXPAND /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-%Y%m%d
(97599) Thu Oct 31 12:34:28 2019: Debug: auth_log:    --> /var/log/radacct/.../auth-20191031
(97599) Thu Oct 31 12:34:28 2019: Debug: auth_log: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-%Y%m%d expands to
----->>> (97599) Thu Oct 31 12:34:28 2019: WARNING: auth_log: Skipping empty packet
(97599) Thu Oct 31 12:34:28 2019: Debug:     [auth_log] = ok

=====================
         if ((packet->code == PW_CODE_ACCOUNTING_REQUEST) && !packet->vps) {
                 RWDEBUG("Skipping empty packet");
                 return 0;
         }
=====================
That's weird that this packet is treated as accounting request...

On 30.10.2019 23:33, Boris Lytochkin wrote:
>
>
> On 30.10.2019 23:12, Alan DeKok wrote:
>> On Oct 30, 2019, at 4:02 PM, Boris Lytochkin <lytboris at yandex-team.ru> wrote:
>>>>>          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.
>>    Hmm... it should be.  Maybe the reject is coming from *inside* of the TLS tunnel?  Though it shouldn't be.
> I see it as a regular RADIUS packer on the wire:
> ===================
> User Datagram Protocol, Src Port: 1812, Dst Port: 50516
> RADIUS Protocol
>     Code: Access-Reject (3)
>     Packet identifier: 0x1b (27)
>     Length: 20
>     Authenticator: e3cf0e29bd7f3ed4a08d5352574918f4
>     [This is a response to a request in frame 113]
>     [Time from request: 1.003118000 seconds]
> ===================
>
> I'll get raddebug in charge of this then.
>
>>    I checked, uou can use %I to get the packet ID.
> Indeed, I was confused and thought %I is expanded into (REQUEST *)request->number. Thanks!
>

-- 
Boris Lytochkin
Yandex NOC
+7 (495) 739 70 00 ext. 7671