Searching for a hack for changing Voucher to Online Time



  • Hi there,

    we are now starting to use the PFSense Captive Portal instead of our old Windows Solution, but need Vouchers with Online-Time instead of Time-Vouchers running out at defined Time.

    Somebody knows where to implement such a feature or can tell me how to use the Hard-Timeout or Idle-Timeout to stop Voucher counting ?

    Thx for your Help,

    Wolfgang from Austria ….



  • I would also find a connect-time voucher more useful than the existing elapsed-time voucher.



  • You can hack the source for this.
    I do not think anyone has plans for now to achieve something like that.



  • Hello !

    I wonder if someone found a solution for this. As it is now the use of vouchers are very limited. I search for a solution to have connection time based vouchers.
    If it is not possible in PFsense, anyone knows of any other software doing this ?

    best regards
    Toby



  • Maybe someone has the answer for this???



  • You can do this with CP + freeradius2 package.
    But you cannot use vouchers - you must use username/password.

    http://doc.pfsense.org/index.php/FreeRADIUS_2.x_package#Amount_of_Time



  • but can I generate users for hours???



  • Just go to portal.pfsense.org and ask for such thing and how much it would cost!

    Its not easy change to use vouchers for such thing.
    For using a radiu server with user/pass than that should be ok with 2.0.



  • @ypas:

    but can I generate users for hours???

    In freeradius2 package you can setup a user that has an amount of time.
    If you setup 60min daily than the user has every day 60min of online time. it is up to the user when he uses this time. 10min in the morgning, 30min at lunch and 20min in the afternoon. When it is midnight the time resets and the user has again 60min.

    choose weekly for a week or monthly for a month or never if there should not be any time reset for this user.

    further you are able to set a time range for a user so that the user only can login between 10:00am and 08:00pm.
    The time range can be used together with the amount of time.



  • Thanks for the help.
    I installed freeradius over pfsense, but I have a problem. I create a user with 3 minutes to use the internet (and I also configured the max daily session), and the captive portal closes the session when the time is exceeded, but If I try login again, the captive portal accepts this action and it doesn´t block the attempt to login for time exceeded.
    What´s the problem with my configuration??? any ideas???



  • @ypas:

    Thanks for the help.
    I installed freeradius over pfsense, but I have a problem. I create a user with 3 minutes to use the internet (and I also configured the max daily session), and the captive portal closes the session when the time is exceeded, but If I try login again, the captive portal accepts this action and it doesn´t block the attempt to login for time exceeded.
    What´s the problem with my configuration??? any ideas???

    Please post the entry for this user from the "users" file (FreeRADIUS -> View config)

    Go to

    vi /var/log/radacct/<ip-address>/detail.log</ip-address>
    

    Scroll down and take a look at "session-time" and the value.



  • /usr/local/etc/raddb/users

    "usuario" Cleartext-Password := "usuario", Expiration := "Feb 03 2012", Max-Daily-Session := 60

    I read my radiusd.conf and It has commented the lines of sql counter, so I enable this line, but now the session doesn´t close never. I try change the configuration since the server by command line and I don´t have the mysql. When I installed a freeradius like a packages over pfsense, is mysql also installed????



  • @ypas:

    /usr/local/etc/raddb/users

    "usuario" Cleartext-Password := "usuario", Expiration := "Feb 03 2012", Max-Daily-Session := 60

    I read my radiusd.conf and It has commented the lines of sql counter, so I enable this line, but now the session doesn´t close never. I try change the configuration since the server by command line and I don´t have the mysql. When I installed a freeradius like a packages over pfsense, is mysql also installed????

    Wow, stop.

    We should be careful to not mix up different things:
    Max-Daily-Session is only working "out of the box" if you do not accounting to an *SQL database.
    If you like to enable sqlcounter than do this from GUI and enable what you need. But then you have to modify the sqlcounter.conf to make the queries like you need them for your database and to make Max-Daily-Session work.

    So please only test Max-Daily-Session without any SQL.
    Further you need to enable stop/start accounting on CP and - you should check "Acct_unique" in settings if it isn't working when unchecked.

    Accounting of Max-Daily-Session will be safed in ../raddb/db.maxdaily



  • Thaaaaanks!!!!

    You're right. I disabled the sql option and created an interface with account type (Any tutorial says that) I only had an interface with auth type.



  • @ypas:

    Thaaaaanks!!!!

    You're right. I disabled the sql option and created an interface with account type (Any tutorial says that) I only had an interface with auth type.

    • Don't forget to check "Disable Acct_unique" in FreeRADIUS => Settings.
    • enable accounting on CP (stop/start). counter only work with accounting-stop packets.
    • Simultaneous-Use must be emty, or >2 if you are using "re-authenticate every minute"
    • If you like to prevent simultaneous-use then just check "Disable concurrent connections" on CP
    • If the user has no "logout popup window" the time counting first stops when "idle timeout" or "hard timeout" is reached.


  • Nachtfalke help me please….
    I configured with the options that you said and all works fine, but the session is closed before the time that I configured for the user. For example, if I configured 900 seconds (max-daily-session time), freeradius closes the session at 5 minutes. (The obtained messages is about max time reached.

    I viewed log and I have some strange lines like these:

    Feb 2 16:52:09 radiusd[50504]: Login OK: [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)
    Feb 2 16:52:09 radiusd[50504]: Login OK: [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)
    Feb 2 16:52:31 radiusd[50504]: rlm_radutmp: Login entry for NAS ip_privada port 2 wrong order
    Feb 2 16:52:31 radiusd[50504]: rlm_radutmp: Login entry for NAS ip_privada port 2 wrong order
    Feb 2 16:52:31 radiusd[50504]: Login OK: [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)
    Feb 2 16:52:31 radiusd[50504]: Login OK: [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)
    Feb 2 16:53:32 radiusd[50504]: rlm_radutmp: Logout for NAS ip_privada port 2, but no Login record
    Feb 2 16:53:32 radiusd[50504]: rlm_radutmp: Logout for NAS ip_privada port 2, but no Login record
    Feb 2 16:53:32 radiusd[50504]: Login OK: [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)
    Feb 2 16:53:32 radiusd[50504]: Login OK: [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)
    Feb 2 16:54:32 radiusd[50504]: rlm_radutmp: Login entry for NAS ip_privada port 2 wrong order
    Feb 2 16:54:32 radiusd[50504]: rlm_radutmp: Login entry for NAS ip_privada port 2 wrong order
    Feb 2 16:54:32 radiusd[50504]: Login OK: [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)
    Feb 2 16:54:32 radiusd[50504]: Login OK: [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)
    Feb 2 16:55:33 radiusd[50504]: rlm_radutmp: Logout for NAS ip_privada port 2, but no Login record
    Feb 2 16:55:33 radiusd[50504]: rlm_radutmp: Logout for NAS ip_privada port 2, but no Login record
    Feb 2 16:55:33 radiusd[50504]: Invalid user (rlm_counter: Maximum daily usage time reached): [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)
    Feb 2 16:55:33 radiusd[50504]: Invalid user (rlm_counter: Maximum daily usage time reached): [user] (from client ip_privada port 2 cli 00:15:58:2e:63:42)



  • The syslog output is well known. It's a behaviour for which I opened a ticket on redmine but we are not sure where the problem exactly lies.
    Probably it is CP or better the form/orader/attributes the CP sends to RADIUS and vice-versa.

    To your "time problem":
    Did you create a completly new user to make sure that this user isn't counted in the database and thus the logout was earlier than expected ?

    Can you do the test with another counter like "weekly" and a new user ?

    Are you using pfsense 2.0.1 ? If yes, then please try to gitsync because ermal fixed a problem with differen NAS-IP-Attribute.
    http://doc.pfsense.org/index.php/Updating_pfSense_code_between_snapshots
    Just start this from console:

    pfSsh.php playback gitsync RELENG_2_0
    

    Perhaps do a reboot after that.



  • Yes, I tried with many alternatives (new users with different characteristics) I also tried disabling the "reauthentication every minute" option, but now I have Internet all the time.

    I read the error "no login record" is because the start packet isn´t send to the NAS server. maybe is it the problem???



  • @ypas:

    Yes, I tried with many alternatives (new users with different characteristics) I also tried disabling the "reauthentication every minute" option, but now I have Internet all the time.

    I read the error "no login record" is because the start packet isn´t send to the NAS server. maybe is it the problem???

    If I find some time over weekend I will try that at home again with Max-Daily-Session and so on.

    For the other problem take a look here:
    http://redmine.pfsense.org/issues/2143
    And here:
    http://lists.pfsense.org/pipermail/dev/2012-January/000118.html



  • Hey guys,

    you are absolutly correct! I cannot explain how I could miss that when I tested the counter module.
    There is a bug in CP when sending the Acct-Session-Time attribute and "stop/start accounting" is enabled.

    Acct-Session time is the time between an accounting-start and an accounting-stop packet. So when accounting-stop is sent from the NAS then the NAS must reset the Acct-Session-Time to zero.

    This is explained here by another user:

    http://forum.pfsense.org/index.php/topic,39987.0.html
    

    And I hope I can explain it here with my logs:

    rad_recv: Accounting-Request packet from host 192.168.0.22 port 20552, id=173, length=198
            NAS-IP-Address = 192.168.0.22
            NAS-Identifier = "pfsense.localdomain"
            User-Name = "peter4"
            Acct-Status-Type = Stop
            Acct-Session-Time = 220
            Acct-Authentic = RADIUS
            Service-Type = Login-User
            NAS-Port-Type = Ethernet
            NAS-Port = 2
            Acct-Session-Id = "d47daeacc0997abd"
            Framed-IP-Address = 192.168.0.98
            Called-Station-Id = "192.168.42.129"
            Calling-Station-Id = "00:04:23:5c:9d:19"
            Acct-Input-Packets = 46
            Acct-Input-Octets = 15045
            Acct-Input-Gigawords = 0
            Acct-Output-Packets = 57
            Acct-Output-Octets = 70307
            Acct-Output-Gigawords = 0
            Acct-Session-Time = 220
            Acct-Terminate-Cause = NAS-Request
    # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group preacct {...}
    ++[preprocess] returns ok
    [suffix] No '@' in User-Name = "peter4", skipping NULL due to config.
    ++[suffix] returns noop
    [ntdomain] No '\' in User-Name = "peter4", skipping NULL due to config.
    ++[ntdomain] returns noop
    ++[files] returns noop
    # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group accounting {...}
    [detail]        expand: %{Packet-Src-IP-Address} -> 192.168.0.22
    [detail]        expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.0.22/detail-20120203
    [detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.0.22/detail-20120203
    [detail]        expand: %t -> Fri Feb  3 21:08:31 2012
    ++[detail] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=299.
    rlm_counter: User=peter4, New Counter=519.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[daily] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=299.
    rlm_counter: User=peter4, New Counter=519.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[weekly] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=299.
    rlm_counter: User=peter4, New Counter=519.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[monthly] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=299.
    rlm_counter: User=peter4, New Counter=519.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[forever] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=22563.
    rlm_counter: User=peter4, New Counter=37608.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxdailyupload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=135829.
    rlm_counter: User=peter4, New Counter=206136.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxdailydownload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=22563.
    rlm_counter: User=peter4, New Counter=37608.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxweeklyupload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=135829.
    rlm_counter: User=peter4, New Counter=206136.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxweeklydownload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=22563.
    rlm_counter: User=peter4, New Counter=37608.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxmonthlyupload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=135829.
    rlm_counter: User=peter4, New Counter=206136.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxmonthlydownload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=22563.
    rlm_counter: User=peter4, New Counter=37608.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxupload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=135829.
    rlm_counter: User=peter4, New Counter=206136.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxdownload] returns ok
    ++[unix] returns ok
    [radutmp]       expand: /var/log/radutmp -> /var/log/radutmp
    [radutmp]       expand: %{User-Name} -> peter4
    ++[radutmp] returns ok
    ++[exec] returns noop
    [attr_filter.accounting_response]       expand: %{User-Name} -> peter4
    attr_filter: Matched entry DEFAULT at line 12
    ++[attr_filter.accounting_response] returns updated
    Sending Accounting-Response of id 173 to 192.168.0.22 port 20552
    Finished request 11.
    Cleaning up request 11 ID 173 with timestamp +239
    Going to the next request
    Ready to process requests.
    rad_recv: Accounting-Request packet from host 192.168.0.22 port 35125, id=153, length=142
            NAS-IP-Address = 192.168.0.22
            NAS-Identifier = "pfsense.localdomain"
            User-Name = "peter4"
            Acct-Status-Type = Start
            Acct-Authentic = RADIUS
            Service-Type = Login-User
            NAS-Port-Type = Ethernet
            NAS-Port = 2
            Acct-Session-Id = "d47daeacc0997abd"
            Framed-IP-Address = 192.168.0.98
            Called-Station-Id = "192.168.0.22"
            Calling-Station-Id = "00:04:23:5c:9d:19"
    # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group preacct {...}
    ++[preprocess] returns ok
    [suffix] No '@' in User-Name = "peter4", skipping NULL due to config.
    ++[suffix] returns noop
    [ntdomain] No '\' in User-Name = "peter4", skipping NULL due to config.
    ++[ntdomain] returns noop
    ++[files] returns noop
    # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group accounting {...}
    [detail]        expand: %{Packet-Src-IP-Address} -> 192.168.0.22
    [detail]        expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.0.22/detail-20120203
    [detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.0.22/detail-20120203
    [detail]        expand: %t -> Fri Feb  3 21:08:31 2012
    ++[detail] returns ok
    rlm_counter: We only run on Accounting-Stop packets.
    ++[daily] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[weekly] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[monthly] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[forever] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxdailyupload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxdailydownload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxweeklyupload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxweeklydownload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxmonthlyupload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxmonthlydownload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxupload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxdownload] returns noop
    ++[unix] returns ok
    [radutmp]       expand: /var/log/radutmp -> /var/log/radutmp
    [radutmp]       expand: %{User-Name} -> peter4
    rlm_radutmp: Login entry for NAS captiveportal port 2 wrong order
    ++[radutmp] returns ok
    ++[exec] returns noop
    [attr_filter.accounting_response]       expand: %{User-Name} -> peter4
    attr_filter: Matched entry DEFAULT at line 12
    ++[attr_filter.accounting_response] returns updated
    Sending Accounting-Response of id 153 to 192.168.0.22 port 35125
    Finished request 12.
    Cleaning up request 12 ID 153 with timestamp +239
    Going to the next request
    Ready to process requests.
    rad_recv: Access-Request packet from host 192.168.0.22 port 49822, id=242, length=130
            NAS-IP-Address = 192.168.0.22
            NAS-Identifier = "pfsense.localdomain"
            User-Name = "peter4"
            User-Password = "pan4"
            Service-Type = Login-User
            NAS-Port-Type = Ethernet
            NAS-Port = 2
            Framed-IP-Address = 192.168.0.98
            Called-Station-Id = "192.168.0.22"
            Calling-Station-Id = "00:04:23:5c:9d:19"
    # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group authorize {...}
    ++[preprocess] returns ok
    ++[chap] returns noop
    ++[mschap] returns noop
    ++[digest] returns noop
    [suffix] No '@' in User-Name = "peter4", skipping NULL due to config.
    ++[suffix] returns noop
    [ntdomain] No '\' in User-Name = "peter4", skipping NULL due to config.
    ++[ntdomain] returns noop
    [eap] No EAP-Message, not doing EAP
    ++[eap] returns noop
    [files] users: Matched entry peter4 at line 2
    ++[files] returns ok
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[daily] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[weekly] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[monthly] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[forever] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key Found.
    rlm_counter: Check item = 500000, Count = 37608
    rlm_counter: res is greater than zero
    rlm_counter: (Check item - counter) is greater than zero
    rlm_counter: Authorized user peter4, check_item=500000, counter=37608
    rlm_counter: Sent Reply-Item for user peter4, Type=Session-Timeout, value=462392
    ++[maxdailyupload] returns ok
    rlm_counter: Entering module authorize code
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key Found.
    rlm_counter: Check item = 500000, Count = 206136
    rlm_counter: res is greater than zero
    rlm_counter: (Check item - counter) is greater than zero
    rlm_counter: Authorized user peter4, check_item=500000, counter=206136
    rlm_counter: Sent Reply-Item for user peter4, Type=Session-Timeout, value=293864
    ++[maxdailydownload] returns ok
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxweeklyupload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxweeklydownload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxmonthlyupload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxmonthlydownload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxupload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxdownload] returns noop
    rlm_checkval: Item Name: Calling-Station-Id, Value: 00:04:23:5c:9d:19
    rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
    ++[checkval] returns notfound
    ++[expiration] returns noop
    ++[logintime] returns noop
    ++[pap] returns updated
    Found Auth-Type = PAP
    # Executing group from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group PAP {...}
    [pap] login attempt with password "pan4"
    [pap] Using clear text password "pan4"
    [pap] User authenticated successfully
    ++[pap] returns ok
    Login OK: [peter4] (from client captiveportal port 2 cli 00:04:23:5c:9d:19)
    # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group post-auth {...}
    ++[exec] returns noop
    Sending Access-Accept of id 242 to 192.168.0.22 port 49822
            Acct-Input-Octets = 462392
            Acct-Output-Octets = 293864
    Finished request 13.
    Going to the next request
    Waking up in 4.9 seconds.
    Cleaning up request 13 ID 242 with timestamp +239
    Ready to process requests.
    
    rad_recv: Accounting-Request packet from host 192.168.0.22 port 44935, id=224, length=198
            NAS-IP-Address = 192.168.0.22
            NAS-Identifier = "pfsense.localdomain"
            User-Name = "peter4"
            Acct-Status-Type = Stop
            Acct-Session-Time = 281
            Acct-Authentic = RADIUS
            Service-Type = Login-User
            NAS-Port-Type = Ethernet
            NAS-Port = 2
            Acct-Session-Id = "d47daeacc0997abd"
            Framed-IP-Address = 192.168.0.98
            Called-Station-Id = "192.168.42.129"
            Calling-Station-Id = "00:04:23:5c:9d:19"
            Acct-Input-Packets = 75
            Acct-Input-Octets = 21410
            Acct-Input-Gigawords = 0
            Acct-Output-Packets = 110
            Acct-Output-Octets = 112730
            Acct-Output-Gigawords = 0
            Acct-Session-Time = 281
            Acct-Terminate-Cause = NAS-Request
    # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group preacct {...}
    ++[preprocess] returns ok
    [suffix] No '@' in User-Name = "peter4", skipping NULL due to config.
    ++[suffix] returns noop
    [ntdomain] No '\' in User-Name = "peter4", skipping NULL due to config.
    ++[ntdomain] returns noop
    ++[files] returns noop
    # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group accounting {...}
    [detail]        expand: %{Packet-Src-IP-Address} -> 192.168.0.22
    [detail]        expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.0.22/detail-20120203
    [detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.0.22/detail-20120203
    [detail]        expand: %t -> Fri Feb  3 21:09:32 2012
    ++[detail] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=519.
    rlm_counter: User=peter4, New Counter=800.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[daily] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=519.
    rlm_counter: User=peter4, New Counter=800.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[weekly] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=519.
    rlm_counter: User=peter4, New Counter=800.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[monthly] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=519.
    rlm_counter: User=peter4, New Counter=800.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[forever] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=37608.
    rlm_counter: User=peter4, New Counter=59018.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxdailyupload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=206136.
    rlm_counter: User=peter4, New Counter=318866.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxdailydownload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=37608.
    rlm_counter: User=peter4, New Counter=59018.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxweeklyupload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=206136.
    rlm_counter: User=peter4, New Counter=318866.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxweeklydownload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=37608.
    rlm_counter: User=peter4, New Counter=59018.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxmonthlyupload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=206136.
    rlm_counter: User=peter4, New Counter=318866.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxmonthlydownload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=37608.
    rlm_counter: User=peter4, New Counter=59018.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxupload] returns ok
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key found.
    rlm_counter: Counter Unique ID = ''
    rlm_counter: User=peter4, Counter=206136.
    rlm_counter: User=peter4, New Counter=318866.
    rlm_counter: Storing new value in database.
    rlm_counter: New value stored successfully.
    ++[maxdownload] returns ok
    ++[unix] returns ok
    [radutmp]       expand: /var/log/radutmp -> /var/log/radutmp
    [radutmp]       expand: %{User-Name} -> peter4
    rlm_radutmp: Logout for NAS captiveportal port 2, but no Login record
    ++[radutmp] returns ok
    ++[exec] returns noop
    [attr_filter.accounting_response]       expand: %{User-Name} -> peter4
    attr_filter: Matched entry DEFAULT at line 12
    ++[attr_filter.accounting_response] returns updated
    Sending Accounting-Response of id 224 to 192.168.0.22 port 44935
    Finished request 14.
    Cleaning up request 14 ID 224 with timestamp +300
    Going to the next request
    Ready to process requests.
    rad_recv: Accounting-Request packet from host 192.168.0.22 port 22100, id=218, length=142
            NAS-IP-Address = 192.168.0.22
            NAS-Identifier = "pfsense.localdomain"
            User-Name = "peter4"
            Acct-Status-Type = Start
            Acct-Authentic = RADIUS
            Service-Type = Login-User
            NAS-Port-Type = Ethernet
            NAS-Port = 2
            Acct-Session-Id = "d47daeacc0997abd"
            Framed-IP-Address = 192.168.0.98
            Called-Station-Id = "192.168.0.22"
            Calling-Station-Id = "00:04:23:5c:9d:19"
    # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group preacct {...}
    ++[preprocess] returns ok
    [suffix] No '@' in User-Name = "peter4", skipping NULL due to config.
    ++[suffix] returns noop
    [ntdomain] No '\' in User-Name = "peter4", skipping NULL due to config.
    ++[ntdomain] returns noop
    ++[files] returns noop
    # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group accounting {...}
    [detail]        expand: %{Packet-Src-IP-Address} -> 192.168.0.22
    [detail]        expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.0.22/detail-20120203
    [detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.0.22/detail-20120203
    [detail]        expand: %t -> Fri Feb  3 21:09:32 2012
    ++[detail] returns ok
    rlm_counter: We only run on Accounting-Stop packets.
    ++[daily] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[weekly] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[monthly] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[forever] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxdailyupload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxdailydownload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxweeklyupload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxweeklydownload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxmonthlyupload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxmonthlydownload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxupload] returns noop
    rlm_counter: We only run on Accounting-Stop packets.
    ++[maxdownload] returns noop
    ++[unix] returns ok
    [radutmp]       expand: /var/log/radutmp -> /var/log/radutmp
    [radutmp]       expand: %{User-Name} -> peter4
    ++[radutmp] returns ok
    ++[exec] returns noop
    [attr_filter.accounting_response]       expand: %{User-Name} -> peter4
    attr_filter: Matched entry DEFAULT at line 12
    ++[attr_filter.accounting_response] returns updated
    Sending Accounting-Response of id 218 to 192.168.0.22 port 22100
    Finished request 15.
    Cleaning up request 15 ID 218 with timestamp +300
    Going to the next request
    Ready to process requests.
    rad_recv: Access-Request packet from host 192.168.0.22 port 28978, id=92, length=130
            NAS-IP-Address = 192.168.0.22
            NAS-Identifier = "pfsense.localdomain"
            User-Name = "peter4"
            User-Password = "pan4"
            Service-Type = Login-User
            NAS-Port-Type = Ethernet
            NAS-Port = 2
            Framed-IP-Address = 192.168.0.98
            Called-Station-Id = "192.168.0.22"
            Calling-Station-Id = "00:04:23:5c:9d:19"
    # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group authorize {...}
    ++[preprocess] returns ok
    ++[chap] returns noop
    ++[mschap] returns noop
    ++[digest] returns noop
    [suffix] No '@' in User-Name = "peter4", skipping NULL due to config.
    ++[suffix] returns noop
    [ntdomain] No '\' in User-Name = "peter4", skipping NULL due to config.
    ++[ntdomain] returns noop
    [eap] No EAP-Message, not doing EAP
    ++[eap] returns noop
    [files] users: Matched entry peter4 at line 2
    ++[files] returns ok
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[daily] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[weekly] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[monthly] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[forever] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key Found.
    rlm_counter: Check item = 500000, Count = 59018
    rlm_counter: res is greater than zero
    rlm_counter: (Check item - counter) is greater than zero
    rlm_counter: Authorized user peter4, check_item=500000, counter=59018
    rlm_counter: Sent Reply-Item for user peter4, Type=Session-Timeout, value=440982
    ++[maxdailyupload] returns ok
    rlm_counter: Entering module authorize code
    rlm_counter: Searching the database for key 'peter4'
    rlm_counter: Key Found.
    rlm_counter: Check item = 500000, Count = 318866
    rlm_counter: res is greater than zero
    rlm_counter: (Check item - counter) is greater than zero
    rlm_counter: Authorized user peter4, check_item=500000, counter=318866
    rlm_counter: Sent Reply-Item for user peter4, Type=Session-Timeout, value=181134
    ++[maxdailydownload] returns ok
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxweeklyupload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxweeklydownload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxmonthlyupload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxmonthlydownload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxupload] returns noop
    rlm_counter: Entering module authorize code
    rlm_counter: Could not find Check item value pair
    ++[maxdownload] returns noop
    rlm_checkval: Item Name: Calling-Station-Id, Value: 00:04:23:5c:9d:19
    rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
    ++[checkval] returns notfound
    ++[expiration] returns noop
    ++[logintime] returns noop
    ++[pap] returns updated
    Found Auth-Type = PAP
    # Executing group from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group PAP {...}
    [pap] login attempt with password "pan4"
    [pap] Using clear text password "pan4"
    [pap] User authenticated successfully
    ++[pap] returns ok
    Login OK: [peter4] (from client captiveportal port 2 cli 00:04:23:5c:9d:19)
    # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
    +- entering group post-auth {...}
    ++[exec] returns noop
    Sending Access-Accept of id 92 to 192.168.0.22 port 28978
            Acct-Input-Octets = 440982
            Acct-Output-Octets = 181134
    Finished request 16.
    Going to the next request
    Waking up in 4.9 seconds.
    Cleaning up request 16 ID 92 with timestamp +300
    Ready to process requests.
    
    
    line 19:
    Acct-Output-Octets = 70307
    This is sent from NAS to RADIUS
    
    line 126 - 133:
    The old counter is (135829) + the value from line 19 (70307) is the new counter value in line 130 (206136)
    
    line 330:
    Acct-Output-Octets = 112730
    This is sent from NAS to RADIUS
    
    line 437 - 444:
    The old counter is (206136) + the vakue from line 330 (112730) is the new counter value in line 441 (318866)
    

    The rlm_counter module says on an accounting-start packet:

    rlm_counter: We only run on Accounting-Stop packets.
    

    This is the only way it makes sense. When an Accounting-start is recieved then the packets will be counted until the accounting-stop.
    Normally an Accounting-Stop packet is recieved by RADIUS when the NAS detects that the client disconnected. After the disconnect of the client the NAS resets the values - of course - it doesn't know the client anymore.
    If the client connects later again than the NAS doesn't know the client, it sends an accounting-start packet - start counting up from zero.

    This is working correctly in Acct-Output-Octets as you can see from the debug above.
    But it isn't working for Acct-Session-Time.

    I can not find any rfc/source where it is explicit written down that after an accounting-stop packet the Acct-Session-Time must be resetet to zero BUT I bought a FreeRADIUS book which explains the rlm_counter module and the counter in the book, the counter on the freeradius.org page are exactly the same and this leads me to the opinion that the counter is correct and the Acct-Session-Time RESET is missing. Because why should the same counter module for octets work the other way as for time?

    I will open a ticket on redmine for this - hopefully this can be fixed easily by someone who knows the CP code - probably ermal  :)

    –-- edit ----

    Here we can see what is happening with Acct-Session-Time when there is "no accounting updates" enabled on CP and The users gets disconnected from the GUI after ~120 seconds (Status => Captive Portal), then reconnects with same username/pass and gets again disconnected from GUI after a few seconds.

    Counter is counting the correct value and Acct-Session-Time will be reseted after accounting-stop.



  • Thanks a lot!!!
    A big problem with that.



  • Try this out https://redmine.pfsense.org/issues/2164 and let me know.


Log in to reply