Accounting-Packets from Huawei NAS randomly not being written to the database

classic Classic list List threaded Threaded
6 messages Options
| Threaded
Open this post in threaded view
|

Accounting-Packets from Huawei NAS randomly not being written to the database

Antônio Modesto
Hello everyone,


I have some radius servers configured to use decoupled-accounting to avoid overwhelming the database with real-time writes. In all of them I am having the same problem. Some accounting packets sent from Huawei devices are not being written to the database. I have set up a second detail log file to check if the packets were being sent by the NAS. For example:


Packet received from the NAS, stored in the second detail file:


Fri Aug  7 08:54:43 2020
        User-Name = "andersonoliveira"
        NAS-Port = 3162917
        NAS-IP-Address = X.X.X.X
        Framed-IP-Address = 100.64.218.153
        NAS-Identifier = "TI5-BRAS01"
        Acct-Status-Type = Stop
        Acct-Delay-Time = 0
        Acct-Input-Octets = 0
        Acct-Output-Octets = 0
        Acct-Session-Id = "TI5-BRA00304080500000a598ccAAADbA"
        Acct-Authentic = RADIUS
        Acct-Session-Time = 200
        Acct-Input-Packets = 0
        Acct-Output-Packets = 0
        Acct-Terminate-Cause = Lost-Carrier
        Acct-Input-Gigawords = 0
        Acct-Output-Gigawords = 0
        Event-Timestamp = "Aug  7 2020 08:54:43 -03"
        NAS-Port-Type = Ethernet
        Calling-Station-Id = "58:10:8c:07:48:8f"
        NAS-Port-Id = "slot=0;subslot=3;port=4;vlanid=805;"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Connect-Info = "1300000/1000000"
        Idle-Timeout = 0
        Session-Timeout = 0
        Huawei-IPHost-Addr = "100.64.218.153 58:10:8c:07:48:8f"
        Huawei-Input-Peak-Rate = 1000000
        Huawei-Input-Peak-Rate = 1000000
        Huawei-Input-Average-Rate = 1000000
        Huawei-Output-Peak-Rate = 1300000
        Huawei-Output-Average-Rate = 1300000
        Huawei-Priority = 15
        Huawei-Connect-ID = 13206
        Huawei-Domain-Name = "provedor_pppoe"
        Huawei-Accounting-Level = 0
        Huawei-Up-Priority = 15
        Huawei-Down-Priority = 15
        Huawei-Acct-IPv6-Input-Octets = 0
        Huawei-Acct-IPv6-Output-Octets = 0
        Huawei-Acct-IPv6-Input-Packets = 0
        Huawei-Acct-IPv6-Output-Packets = 0
        Huawei-Acct-IPv6-Input-Gigawords = 0
        Huawei-Acct-IPv6-Output-Gigawords = 0
        Huawei-User-Mac = "58:10:8c:07:48:8f"
        Huawei-Acct-Update-Address = 0
        Huawei-Input-Burst-Size = 625000
        Huawei-Output-Burst-Size = 812504
        Huawei-Input-Peak-Burst-Size = 625000
        Huawei-Output-Peak-Burst-Size = 812504
        Timestamp = 1596801283



Record in the redacct table:

-[ RECORD 5 ]-------+----------------------------------
username            | andersonoliveira
acctsessionid       | TI5-BRA00304080500000a598ccAAADbA
acctstarttime       | 2020-08-07 08:51:23-03
acctlocalupdatetime | 2020-08-07 08:51:23-03
acctstoptime        |



As you can see, neither acctlocalupdatetime or acctstoptime were updated with the correct timestamps from the packet received by the NAS. I checked the logs and I couldn’t find any error message related to this. As the server is in production, enabling the debug creates a lot of output.

The only thing I think could be causing this is this condition I have in my accounting section:

if (noop) {
        ok
}

What do you guys suggest?


Thanks in advance.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
| Threaded
Open this post in threaded view
|

Re: Accounting-Packets from Huawei NAS randomly not being written to the database

Alan DeKok-2
On Aug 7, 2020, at 8:26 AM, Antônio Modesto <[hidden email]> wrote:
>
> I have some radius servers configured to use decoupled-accounting to avoid overwhelming the database with real-time writes.

  Databases should be able to keep up, with some DB tweaking. But decoupled-accounting does make it simpler.

> In all of them I am having the same problem. Some accounting packets sent from Huawei devices are not being written to the database. I have set up a second detail log file to check if the packets were being sent by the NAS. For example:

  Look at the debug output to see why.  Look at the logic you have around using the SQL module.

> As you can see, neither acctlocalupdatetime or acctstoptime were updated with the correct timestamps from the packet received by the NAS. I checked the logs and I couldn’t find any error message related to this. As the server is in production, enabling the debug creates a lot of output.

  You can set up a test server, and use "radclient".  Take a copy of the detail file entry, and use radclient to send it to the test server.

> The only thing I think could be causing this is this condition I have in my accounting section:
>
> if (noop) {
> ok
> }

  That doesn't say "skip writing to the SQL module"

> What do you guys suggest?

  Set up a test server and run it in debug mode.

  Alan DeKok.


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
| Threaded
Open this post in threaded view
|

Re: Accounting-Packets from Huawei NAS randomly not being written to the database

Antônio Modesto


> On 7 Aug 2020, at 09:33, Alan DeKok <[hidden email]> wrote:
>
>
>  You can set up a test server, and use "radclient".  Take a copy of the detail file entry, and use radclient to send it to the test server.
>


Hi Alan, thanks for your response.

I tried to resend the same packet using radclient as you suggested (on the same server) and it worked. The record in the database was updated. I will try to store some compressed debug output for a longer period to see if I can find something that explains this behaviour.

radclient -x -f /tmp/record.txt 127.1.1.2 acct testing123
Sent Accounting-Request Id 22 from 127.1.1.2:21530 to 127.1.1.2:1813 length 617
        User-Name = "andersonoliveira"
        NAS-Port = 3162917
        NAS-IP-Address = 177.66.167.254
        Framed-IP-Address = 100.64.218.153
        NAS-Identifier = "TI5-BRAS01"
        Acct-Status-Type = Stop
        Acct-Delay-Time = 0
        Acct-Input-Octets = 0
        Acct-Output-Octets = 0
        Acct-Session-Id = "TI5-BRA00304080500000a598ccAAADbA"
        Acct-Authentic = RADIUS
        Acct-Session-Time = 200
        Acct-Input-Packets = 0
        Acct-Output-Packets = 0
        Acct-Terminate-Cause = Lost-Carrier
        Acct-Input-Gigawords = 0
        Acct-Output-Gigawords = 0
        Event-Timestamp = "Aug  7 2020 08:54:43 -03"
        NAS-Port-Type = Ethernet
        Calling-Station-Id = "58:10:8c:07:48:8f"
        NAS-Port-Id = "slot=0;subslot=3;port=4;vlanid=805;"
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Connect-Info = "1300000/1000000"
        Idle-Timeout = 0
        Session-Timeout = 0
        Huawei-IPHost-Addr = "100.64.218.153 58:10:8c:07:48:8f"
        Huawei-Input-Peak-Rate = 1000000
        Huawei-Input-Peak-Rate = 1000000
        Huawei-Input-Average-Rate = 1000000
        Huawei-Output-Peak-Rate = 1300000
        Huawei-Output-Average-Rate = 1300000
        Huawei-Priority = 15
        Huawei-Connect-ID = 13206
        Huawei-Domain-Name = "provedor_pppoe"
        Huawei-Accounting-Level = 0
        Huawei-Up-Priority = 15
        Huawei-Down-Priority = 15
        Huawei-Acct-IPv6-Input-Octets = 0
        Huawei-Acct-IPv6-Output-Octets = 0
        Huawei-Acct-IPv6-Input-Packets = 0
        Huawei-Acct-IPv6-Output-Packets = 0
        Huawei-Acct-IPv6-Input-Gigawords = 0
        Huawei-Acct-IPv6-Output-Gigawords = 0
        Huawei-User-Mac = "58:10:8c:07:48:8f"
        Huawei-Acct-Update-Address = 0
        Huawei-Input-Burst-Size = 625000
        Huawei-Output-Burst-Size = 812504
        Huawei-Input-Peak-Burst-Size = 625000
        Huawei-Output-Peak-Burst-Size = 812504
Received Accounting-Response Id 22 from 127.1.1.2:1813 to 127.1.1.2:21530 length 20


Acctstoptime and acctlocalupdatetime were correctly updated:

radius=# select username, acctsessionid, acctstarttime, acctstoptime, acctlocalupdatetime from radacct where acctsessionid = 'TI5-BRA00304080500000a598ccAAADbA';
-[ RECORD 1 ]-------+----------------------------------
username            | andersonoliveira
acctsessionid       | TI5-BRA00304080500000a598ccAAADbA
acctstarttime       | 2020-08-07 08:51:23-03
acctstoptime        | 2020-08-07 08:54:43-03
acctlocalupdatetime | 2020-08-07 10:20:35-03



Thanks.


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
| Threaded
Open this post in threaded view
|

Re: Accounting-Packets from Huawei NAS randomly not being written to the database

Antônio Modesto
Hi folks,


I tried to run the server in debug mode for the whole afternoon to see if I could find something, but not even a single packet was lost during this time. The most intriguing is that I started the server in debug mode at 02:00 PM (GMT -3), the last packet lost was at 01:56 (GMT -3). I also noticed that these warnings stopped just after I started the server in debug mode:


Aug  7 13:59:27 radius-server radiusd[34270]: detail (/var/log/radacct/detail/detail-*:*): Read empty packet from file /var/log/radacct/detail/detail.work


I find this really weird, because this problem happens quite frequently. I didn’t mention this before but I am running FreeRADIUS Version 3.0.17.


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
| Threaded
Open this post in threaded view
|

Re: Accounting-Packets from Huawei NAS randomly not being written to the database

Alan DeKok-2
On Aug 7, 2020, at 4:50 PM, Antônio Modesto <[hidden email]> wrote:
> I tried to run the server in debug mode for the whole afternoon to see if I could find something, but not even a single packet was lost during this time. The most intriguing is that I started the server in debug mode at 02:00 PM (GMT -3), the last packet lost was at 01:56 (GMT -3). I also noticed that these warnings stopped just after I started the server in debug mode:
>
>
> Aug  7 13:59:27 radius-server radiusd[34270]: detail (/var/log/radacct/detail/detail-*:*): Read empty packet from file /var/log/radacct/detail/detail.work
>
>
> I find this really weird, because this problem happens quite frequently. I didn’t mention this before but I am running FreeRADIUS Version 3.0.17.

  Try v3.0.x from Github: https://github.com/FreeRADIUS/freeradius-server/archive/v3.0.x.zip

   It has many fixes over 3.0.17.  One of these may be affecting you.

  Alan DeKok.


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
| Threaded
Open this post in threaded view
|

Re: Accounting-Packets from Huawei NAS randomly not being written to the database

Antônio Modesto

>
>  Try v3.0.x from Github: https://github.com/FreeRADIUS/freeradius-server/archive/v3.0.x.zip
>
>   It has many fixes over 3.0.17.  One of these may be affecting you.
>
>  Alan DeKok.

Thanks, I’ll check that out later, I changed our config to realtime accounting and it is working well so far, let’s see what happens.


Thanks again for the willingness to help.


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html