Project

General

Profile

Bug #2164

Captive Portal - RADIUS - Acct-Session-Time does not reset when "stop/start accounting" is enabled

Added by Alexander Wilke over 7 years ago. Updated over 3 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
Captive Portal
Target version:
Start date:
02/03/2012
Due date:
% Done:

0%

Estimated time:
Affected Version:
All
Affected Architecture:

Description

Acct-Session-Time needs reset to value 0 when accounting-stop packet is sent. This is done when "no accounting updates" is enabled but it isn't done when "stop/start accounting is enabled". So the rlm_counter module cannot count the correct values for Session-Timeout.
But on other attributes like - Acct-Output-Octets - CP resets the value to zero after accounting-stop packet. This is how it should be.

For more debug messages take a look at the following forum post:
http://forum.pfsense.org/index.php/topic,39396.msg240033.html#msg240033

cp.diff (2.14 KB) cp.diff Ermal Luçi, 02/09/2012 04:26 PM

Associated revisions

Revision 00de7de6 (diff)
Added by Jim Pingle over 3 years ago

Fix multi-session time counting for the FreeRADIUS start/stop case. Ticket #2164

History

#1 Updated by Ermal Luçi over 7 years ago

Well this is an easy fix if it really works that way.
I am not sure what really the Acc-Session-Time measures but since accounting updates are more or less 60secs by default in pfSense i can turn this into a static value of 60secs!

That should fix your issues and probably account this properly. Since it just measures the time of the session and until the next update is sent for sure 60secs have passed.

If you are ok with it try out this patch:

diff --git a/etc/inc/captiveportal.inc b/etc/inc/captiveportal.inc
index 7c60e10..0b6b3be 100644
--- a/etc/inc/captiveportal.inc
+++ b/etc/inc/captiveportal.inc
@@ -775,11 +775,14 @@ function captiveportal_prune_old() {
                                        RADIUS_ACCOUNTING_STOP($cpentry[1], // ruleno
                                                $cpentry[4], // username
                                                $cpentry[5], // sessionid
-                                               $cpentry[0], // start time
+                                               /* XXX: *start time* Timer is static since prunce records is every 60secs. Max it needs to be configurable with prune records interval */
+                                               $stop_time - 60,
                                                $radiusservers,
                                                $cpentry[2], // clientip
                                                $cpentry[3], // clientmac
-                                               10); // NAS Request
+                                               10, // NAS Request
+                                               false, //Not interim update
+                                               $stop_time);
                                        captiveportal_ipfw_set_context($cpzone);
                                        exec("/sbin/ipfw table 1 entryzerostats {$cpentry[2]}");
                                        exec("/sbin/ipfw table 2 entryzerostats {$cpentry[2]}");
@@ -839,6 +842,8 @@ function captiveportal_disconnect($dbent, $radiusservers,$term_cause = 1,$stop_t
                RADIUS_ACCOUNTING_STOP($dbent[1], // ruleno
                        $dbent[4], // username
                        $dbent[5], // sessionid
+                       /* XXX: *start time* Timer is static since prunce records is every 60secs. Max it needs to be configurable with prune records interval */
+                       $stop_time - 60,
                        $dbent[0], // start time
                        $radiusservers,
                        $dbent[2], // clientip
@@ -914,6 +919,7 @@ function captiveportal_radius_stop_all() {

        $radiusservers = captiveportal_get_radius_servers();
        if (!empty($radiusservers)) {
+               $stop_time = time();
                $cpdb = captiveportal_read_db();
                foreach ($cpdb as $cpentry) {
                        if (empty($cpentry[10]))
@@ -922,11 +928,14 @@ function captiveportal_radius_stop_all() {
                                RADIUS_ACCOUNTING_STOP($cpentry[1], // ruleno
                                        $cpentry[4], // username
                                        $cpentry[5], // sessionid
+                                       /* XXX: *start time* Timer is static since prunce records is every 60secs. Max it needs to be configurable with prune records interval */
+                                       $stop_time - 60,
                                        $cpentry[0], // start time
                                        $radiusservers[$cpentry[10]],
                                        $cpentry[2], // clientip
                                        $cpentry[3], // clientmac
-                                       7); // Admin Reboot
+                                       7, // Admin Reboot
+                                       false, $stop_time);
                        }
                }
        }

#2 Updated by Ermal Luçi over 7 years ago

Attached patch from request

#3 Updated by Alexander Wilke over 7 years ago

Hi,
I didn't get the patch too 100% applied with this command:

patch -p1 < cp.diff

So I did it manually. Not sure if I missed something or not but:
- the counter is now working. Every accounting stop packet increases the counter by 60 seconds. That is ok.
- after the diff there isn't any "start" packet anymore after an accounting stop packet
- CP does not send an accounting stop packet anymore after disconnecting a CP user by GUI

If found a fix for an other "bug":

rlm_radutmp: Logout for NAS CP port 76, but no Login record
rlm_radutmp: Login entry for NAS CP port 76 wrong order

This is happening because the accounting stop/start packets are to short after another. I added this line:

exec("sleep 1");

What is happening:
user authenticates the first time:
accounting start: user gets added to /var/log/radutmp for Simultaneous-Use checks - That's OK
after one minute:
accounting stop: user gets deleted from radutmp file - That's OK
accounting start (too fast): no user gets added to radutmp file
after one minute:
accounting stop: no user found in radutmp file - ERROR: Logout for NAS CP port 76, but no Login record

Sometimes it happens that it is the other way and two accounting start packets lead to th ERROR: Login entry for NAS CP port 76 wrong order

I hope this will help you - and at least me - in any kind of way.
Alexander

#4 Updated by Alexander Wilke over 7 years ago

I am sorry to say that - or better - I am sorry that I posted something wrong on my first post! :-(

I am wrong with that "Acct-Output-Octets" will be reset to zero after an accounting stop packet. That's wrong.
"Acct-Output-Octets" and "Acct-Input-Octets" do not reset after accounting stop.

So "Session-Timeout" and "Acct-X-Octets" need to be reset to zero after an accounting stop packet.
Perhaps we can realize that with something like that:

Acct-X-Octets = "Acct-X-Octets" - "Acct-X-Octets" 

#5 Updated by Chunlin Yao over 6 years ago

I suggest to add a field to cpdb. store the ACCT-START time when calling RADIUS_ACCOUNTING_START

#6 Updated by Alexander Wilke over 6 years ago

Hi,

users in the following two pfsense forum threads applied the patch from Ermal Luçi with success.
Adding the part with:
$stop_time - 60
will fix the accounting issue.

Adding the part with:
exec("sleep 1");
will fix the "accounting stop: no user found in radutmp file - ERROR: Logout for NAS CP port 76, but no Login record" error.

Here are the forum links:
http://forum.pfsense.org/index.php/topic,56306.msg310210.html#msg310210
http://forum.pfsense.org/index.php/topic,57303.0.html

#7 Updated by Michael Newton over 6 years ago

I'm curious what the use case is for "start/stop accounting" at all?

Transparently restricting every session to 60 seconds and then re-starting the session in the background seems like a needless load on the RADIUS server, and counter to the purpose of accounting at all. Since no re-authentication is performed, I can't imagine any purpose to this behaviour.

#8 Updated by Alexander Wilke over 6 years ago

The rlm_counter module is just counting on accounting stop packets. This module is used for time based accounting. It does not work with interim-updates. If you are using a sql database for accounting you do not have this problem as far as I know.

So in general the problem of CP accounting updates is - no matter if if interim or stop - that it only works with a fixed value of 60 seconds. (I know, interim-updates can no be configured by RADIUS reply attribute on pfsense 2.1).

But in general you are right - without re-authentication every minute enabled most counters do not make any sense. That's another thing what should be customizeable on CP - changing the re-auth time.

#9 Updated by Michael Newton over 6 years ago

I would suggest any RADIUS server that can't work with interim update packets is not one worth using. They have been standardized in RFC for over 10 years now. But maybe software like that is why this method is supported in pfSense!?

Everything works fine with interim accounting packets, at least for us. You cannot have a fixed value of 60 seconds for the session time unless you are stopping the session after 60 seconds. Acct-Session-Time indicates the total time, not the time since the last update. It's cumulative over the whole session.

To get back to the original problem you're having, it is simply that the database entry for the CP user isn't getting updated with a new "start" time, because you're separating the CP session and the RADIUS session into two separate things. The best hack to fix it is to fake the RADIUS accounting, that way you don't lose the CP session length in the status pages. The patch above does this but also wrecks session times for users with proper accounting methods. I'd suggest this, based on latest RELENG_2_0 code:

--- captiveportal.inc (saved version)
+++ (current document)
@@ -723,11 +723,13 @@
                     RADIUS_ACCOUNTING_STOP($cpentry[1], // ruleno
                         $cpentry[4], // username
                         $cpentry[5], // sessionid
-                        $cpentry[0], // start time
+                        0, // start time
                         $radiusservers,
                         $cpentry[2], // clientip
                         $cpentry[3], // clientmac
-                        10); // NAS Request
+                        10, // NAS Request
+                        false, //not interim
+                        60); //stop time
                     exec("/sbin/ipfw table 1 entryzerostats {$cpentry[2]}");
                     exec("/sbin/ipfw table 2 entryzerostats {$cpentry[2]}");
                     RADIUS_ACCOUNTING_START($cpentry[1], // ruleno
<pre>

#10 Updated by Alexander Wilke over 6 years ago

I have a different opinion:
Acct-Status-Type indicates when a user is stating a service (start) or is ending a service (stop). The rlm_counter module works with this Acct-Status-Types only. This is not a problem of RADIUS - it is a "problem" or a behaviour of the module. When doing accounting on a mysql database you can count on interim updates. But accounting on mysql is independent from doing accounting with the rlm_counter module.

So the option on CP to offer accounting start/stop is an extra for such a scenario where you just have the rlm_counter module. (We are not talking about the fact that the accounting start/stop repeats every 60s and if this is short or not).

So when an Acct-Status-Type = Start is there then accounting starts and if there is Stop then it must stop because the user ends to use the service. And if there is start then it must start with counting up from 0 because a new service starts. By default CP ist not doing that when accounting start/stop is enabled so it must be fixed with reducing the time by 60s (because CP is doing start/stop every 60s).

I do not use accounting so for me it doesn't matter if it works or not and how it works but it seems to be buggy and the rlm_counter module just works with "stop" packets. If this is RFC or not - I don't know.

#11 Updated by Jim Pingle over 3 years ago

  • Status changed from New to Feedback
  • Assignee set to Jim Pingle
  • Target version set to 2.3
  • Affected Version set to All

I committed a modified version of the code in note 9 along with the sleep for 2.3 as a new option "Start/Stop (FreeRADIUS)". Since it's not clear if the older code was broken for everybody, adding a separate, new, option seemed safer. Testing confirms it seems to work better for single sessions at least.

#12 Updated by Jim Thompson over 3 years ago

bump for resolution

#13 Updated by Jim Pingle over 3 years ago

Tested again on a new setup and single session accounting looks like it's working great. Multi-session needs one more tweak, fix is coming shortly.

#14 Updated by Jim Pingle over 3 years ago

  • Status changed from Feedback to Resolved

Tested this pretty thoroughly and it's OK here. If someone else finds a problem, feel free to comment.

Also available in: Atom PDF