FreeRADIUS2+Accounting

[Alan87i]

Tonight Snap update , I had to save the CP page then save each user in radius2 before they were authenticated. With out doing so it just let them through.

[Nachtfalke]

@Alan87i:

Tonight Snap update , I had to save the CP page then save each user in radius2 before they were authenticated. With out doing so it just let them through.

Are you sure you had to save EVERY user on freeradius2? When changing/editing one user then the complete file will be re-written. So no need to do that with every user.

If you have accounting enabled on CP then you are able to see the logged in users on freeradius.
go to console and use the "radwho" command on this file "/var//log/radutmp" - this file cannot be edited with "vi" or any other editor.

Further check the "Portal Auth" syslog page when this problem occurs that the users have access without credentials.

[Alan87i]

Your right I have to save at least 1 user in FR2 and open CP and save .
A tid bit of the syslog before and after. The top of the log is after PF did an update .
I let it sit for an hour. First thing I did was hit a page with both users(laptops) and I got through.
Tonight I'll remove one user and see if it can connect after an update with out saving cp and FR2 user.

Also you'll see each login writes 2 lines for login OK from radius.
Even more weird is Bandwidthd pumping out 4 lines.

Jun 28 06:15:00 	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 28 06:15:03 	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 28 06:15:05 	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 28 06:15:08 	radiusd[43484]: Loaded virtual server <default>
Jun 28 06:15:08 	radiusd[43779]: Ready to process requests.
Jun 28 06:15:09 	php: : The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'No matching processes were found'
Jun 28 06:15:09 	kernel: em0: promiscuous mode disabled
Jun 28 06:15:13 	bandwidthd: Monitoring subnet 192.168.1.0 with netmask 192.168.1.0
Jun 28 06:15:13 	bandwidthd: Monitoring subnet 192.168.1.0 with netmask 192.168.1.0
Jun 28 06:15:14 	bandwidthd: Opening em0
Jun 28 06:15:14 	bandwidthd: Packet Encoding: Ethernet
Jun 28 06:15:14 	kernel: em0: promiscuous mode enabled
Jun 28 06:15:14 	bandwidthd: Opening em0
Jun 28 06:15:14 	bandwidthd: Opening em0
Jun 28 06:15:14 	bandwidthd: Opening em0
Jun 28 06:15:14 	bandwidthd: Packet Encoding: Ethernet
Jun 28 06:15:14 	bandwidthd: Packet Encoding: Ethernet
Jun 28 06:15:14 	bandwidthd: Packet Encoding: Ethernet
Jun 28 06:15:16 	login: login on ttyv0 as root
Jun 28 06:15:16 	sshlockout[53380]: sshlockout/webConfigurator v3.0 starting up
Jun 28 06:15:17 	check_reload_status: Reloading filter
Jun 28 08:04:06 	check_reload_status: Syncing firewall
Jun 28 08:04:06 	radiusd[43779]: Signalled to terminate
Jun 28 08:04:06 	radiusd[43779]: Exiting normally.
Jun 28 08:04:07 	php: /pkg_edit.php: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 28 08:04:09 	radiusd[44083]: Loaded virtual server <default>
Jun 28 08:04:09 	radiusd[44196]: Ready to process requests.
Jun 28 08:05:24 	check_reload_status: Syncing firewall
Jun 28 08:05:25 	minicron: (/etc/rc.prunecaptiveportal) terminated by signal 15 (Terminated: 15)
Jun 28 08:05:26 	check_reload_status: Reloading filter
Jun 28 08:05:28 	radiusd[44196]: Login OK: [00:1e:ec:ad:45:29] (from client pfsense port 2 cli 00:1e:ec:ad:45:29)
Jun 28 08:05:28 	radiusd[44196]: Login OK: [00:1e:ec:ad:45:29] (from client pfsense port 2 cli 00:1e:ec:ad:45:29)
Jun 28 08:05:29 	root: FreeRADIUS: Used amount of daily traffic by 00:1e:ec:ad:45:29 is 5875 of 10000 MB! The user was accepted!!!
Jun 28 08:05:50 	radiusd[44196]: Login OK: [00:1b:38:b0:e1:51] (from client pfsense port 4 cli 00:1b:38:b0:e1:51)
Jun 28 08:05:50 	radiusd[44196]: Login OK: [00:1b:38:b0:e1:51] (from client pfsense port 4 cli 00:1b:38:b0:e1:51)
Jun 28 08:05:50 	root: FreeRADIUS: Used amount of daily traffic by 00:1b:38:b0:e1:51 is 103 of 2048 MB! The user was accepted!!!</default></default>

Also

Enter an option: 8

[2.1-BETA0][admin@pfsense.testing.com]/root(1): /var//log/radutmp radwho
/var//log/radutmp: Permission denied.
[2.1-BETA0][admin@pfsense.testing.com]/root(2):

[Nachtfalke]

http://freeradius.org/radiusd/man/radwho.html

[2.0.1-RELEASE][admin@pfsense1.hpa]/(9): radwho /var/log/radutmp
Login      Name              What  TTY  When      From            Location

PS: I do not have accounting enabled so no entries here.

@Alan87i
Can you please explain again step by step what you did.
authenticated the user, all is working, updated pfsense, what isn't working.
Thank you!

[Alan87i]

After each snapshot upgrade.
All packages are reinstalled.
I have 2 users in radius.

What I see is both users have access through the wan but CP and FR2 does not authenticate. No log entries CP user status is empty.

I have to save 1 user in FR2 and save on the CP page . Then I see normal log entries and CP shows both users connected.
before next snap I will remove one user and test too see if he is denied. Before following the re-save steps

[Alan87i]

$ radwho /var/log/radutmp
Login      Name              What  TTY  When      From            Location
00:1b:38:b 00:1b:38:b0:e1:51 shell S2   Thu 10:23 192.168.1.1     192.168.1.101
00:1e:ec:a 00:1e:ec:ad:45:29 shell S4   Thu 10:23 192.168.1.1     192.168.1.100
00:1e:ec:a 00:1e:ec:ad:45:29 shell S6   Tue 09:52 192.168.1.1     192.168.1.100

Just updated again too latest snap.
This time I saved CP and tried and the users showed in the logs.

[Nachtfalke]

@Alan87i:

$ radwho /var/log/radutmp
Login      Name              What  TTY  When      From            Location
00:1b:38:b 00:1b:38:b0:e1:51 shell S2   Thu 10:23 192.168.1.1     192.168.1.101
00:1e:ec:a 00:1e:ec:ad:45:29 shell S4   Thu 10:23 192.168.1.1     192.168.1.100
00:1e:ec:a 00:1e:ec:ad:45:29 shell S6   Tue 09:52 192.168.1.1     192.168.1.100

Just updated again too latest snap.
This time I saved CP and tried and the users showed in the logs.

Correct me if I am wrong:
1.) After the snapshot update you didn't change anything on FR2?
2.) After the snapshot update you clicked "Save" on the CP page ?
3.) After that you ran the "radwho" command ?

a) Before you did step 2 - the user could connect to the internet without authentication ?
b) After you did step 2 - the used needed to authenticate on CP ?

Did you set any "Simultaneous-Use" settings on FR2? If yes - delete them. Uncheck the "Disable concurrent connections" on CP page.

Explanation about /var/log/radutmp:
This file only works when accounting is enabled
This file will be used by FR2 to check for simultaneous connections of a user. So when a user authenticates on CP then an accounting packet is sent from CP to FR2 and FR2 writs this user to the file. FR2 will first delete the user from this file if CP tell to do so. If CP is not doing than FR2 is not the fault. Your radwho output shows to connections from same MAC on different days (Tuesday + Thursday).

Can you please do the following:
The next time after you did an update go "Services" and stop FR2.
Then go to console and start FR2 with:

/usr/local/etc/rc.d/radiusd -X

Then try to authenticate on CP and see the output of FR2 - or post the complete output here.

PS: what is happening if an user authenticated correct on PC and after that you just reboot pfsense and then again try to authenticte on CP. Will this work correct or not ?

[Alan87i]

Correct me if I am wrong:
1.) After the snapshot update you didn't change anything on FR2?

yes

2.) After the snapshot update you clicked "Save" on the CP page ?

yes

3.) After that you ran the "radwho" command ?

yes

a) Before you did step 2 - the user could connect to the internet without authentication ?

yes

b) After you did step 2 - the used needed to authenticate on CP ?

Yes happens automatically using mac auth 8.0x in FR2 shows up in log

Did you set any "Simultaneous-Use" settings on FR2? If yes - delete them. Uncheck the "Disable concurrent connections" on CP page.

Disable concurrent logins was checked  Now unchecked

Explanation about /var/log/radutmp:
This file only works when accounting is enabled
This file will be used by FR2 to check for simultaneous connections of a user. So when a user authenticates on CP then an accounting packet is sent from CP to FR2 and FR2 writs this user to the file. FR2 will first delete the user from this file if CP tell to do so. If CP is not doing than FR2 is not the fault. Your radwho output shows to connections from same MAC on different days (Tuesday + Thursday).

Can you please do the following:
The next time after you did an update go "Services" and stop FR2.
Then go to console and start FR2 with:

/usr/local/etc/rc.d/radiusd -X

Then try to authenticate on CP and see the output of FR2 - or post the complete output here.

PS: what is happening if an user authenticated correct on PC and after that you just reboot pfsense and then again try to authenticte on CP. Will this work correct or not ?

I removed 1 of the 2 users . saved and rebooted PF.
After boot up both have internet.
restarted FR2 no change  / saved the 1 user FR2 no change.

Jun 28 12:37:52 	radiusd[55327]: Loaded virtual server <default>
Jun 28 12:37:52 	radiusd[55430]: Ready to process requests.
Jun 28 12:38:25 	radiusd[55430]: Signalled to terminate
Jun 28 12:38:25 	radiusd[55430]: Exiting normally.
Jun 28 12:38:25 	php: /status_services.php: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Jun 28 12:38:28 	radiusd[22872]: Loaded virtual server <default>
Jun 28 12:38:28 	radiusd[23092]: Ready to process requests.</default></default>

Go too CP page click save

Jun 28 12:41:27 	check_reload_status: Syncing firewall
Jun 28 12:41:29 	minicron: (/etc/rc.prunecaptiveportal) terminated by signal 15 (Terminated: 15)
Jun 28 12:41:29 	check_reload_status: Reloading filter
Jun 28 12:41:51 	radiusd[23092]: Login OK: [00:1b:38:b0:e1:51] (from client pfsense port 2 cli 00:1b:38:b0:e1:51)
Jun 28 12:41:51 	radiusd[23092]: Login OK: [00:1b:38:b0:e1:51] (from client pfsense port 2 cli 00:1b:38:b0:e1:51)
Jun 28 12:41:51 	root: FreeRADIUS: Used amount of daily traffic by 00:1b:38:b0:e1:51 is 108 of 2048 MB! The user was accepted!!!
Jun 28 12:42:23 	radiusd[23092]: Login incorrect: [00:1e:ec:ad:45:29/blaa] (from client pfsense port 4 cli 00:1e:ec:ad:45:29)
Jun 28 12:42:23 	radiusd[23092]: Login incorrect: [00:1e:ec:ad:45:29/blaa] (from client pfsense port 4 cli 00:1e:ec:ad:45:29)
Jun 28 12:42:25 	radiusd[23092]: Login incorrect: [00:1e:ec:ad:45:29/blaa] (from client pfsense port 6 cli 00:1e:ec:ad:45:29)
Jun 28 12:42:25 	radiusd[23092]: Login incorrect: [00:1e:ec:ad:45:29/blaa] (from client pfsense port 6 cli 00:1e:ec:ad:45:29)

And all seems fine after that.

[Alan87i]

[2.1-BETA0][admin@pfsense.testing.com]/root(1): /usr/local/etc/rc.d/radiusd -X
/usr/local/etc/rc.d/radiusd: unknown directive '-X'.
Usage: /usr/local/etc/rc.d/radiusd [fast|force|one|quiet](start|stop|restart|rcvar|reload|debug|status|poll)

  }
 Module: Linked to module rlm_chap
 Module: Instantiating module "chap" from file /usr/pbi/freeradius-i386/etc/raddb/modules/chap
 Module: Linked to module rlm_mschap
 Module: Instantiating module "mschap" from file /usr/pbi/freeradius-i386/etc/raddb/modules/mschap
  mschap {
        use_mppe = yes
        require_encryption = no
        require_strong = no
        with_ntdomain_hack = yes
        allow_retry = yes
  }
 Module: Instantiating module "motp" from file /usr/pbi/freeradius-i386/etc/raddb/modules/motp
  exec motp {
        wait = yes
        program = "/usr/local/bin/bash /usr/pbi/freeradius-i386/etc/raddb/scripts/otpverify.sh %{request:User-Name} %{request:User-Password} %{reply:MOTP-Init-Secret} %{reply:MOTP-PIN} %{reply:MOTP-Offset}"
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Linked to module rlm_digest
 Module: Instantiating module "digest" from file /usr/pbi/freeradius-i386/etc/raddb/modules/digest
 Module: Linked to module rlm_unix
 Module: Instantiating module "unix" from file /usr/pbi/freeradius-i386/etc/raddb/modules/unix
  unix {
        radwtmp = "/var/log/radwtmp"
  }
 Module: Linked to module rlm_eap
 Module: Instantiating module "eap" from file /usr/pbi/freeradius-i386/etc/raddb/eap.conf
  eap {
        default_eap_type = "md5"
        timer_expire = 60
        ignore_unknown_eap_types = no
        cisco_accounting_username_bug = no
        max_sessions = 4096
  }
 Module: Linked to sub-module rlm_eap_md5
 Module: Instantiating eap-md5
 Module: Linked to sub-module rlm_eap_leap
 Module: Instantiating eap-leap
 Module: Linked to sub-module rlm_eap_gtc
 Module: Instantiating eap-gtc
   gtc {
        challenge = "Password: "
        auth_type = "PAP"
   }
 Module: Linked to sub-module rlm_eap_tls
 Module: Instantiating eap-tls
   tls {
        rsa_key_exchange = no
        dh_key_exchange = yes
        rsa_key_length = 512
        dh_key_length = 512
        verify_depth = 0
        CA_path = "/usr/pbi/freeradius-i386/etc/raddb/certs"
        pem_file_type = yes
        private_key_file = "/usr/pbi/freeradius-i386/etc/raddb/certs/server.pem"
        certificate_file = "/usr/pbi/freeradius-i386/etc/raddb/certs/server.pem"
        CA_file = "/usr/pbi/freeradius-i386/etc/raddb/certs/ca.pem"
        private_key_password = "whatever"
        dh_file = "/usr/pbi/freeradius-i386/etc/raddb/certs/dh"
        random_file = "/usr/pbi/freeradius-i386/etc/raddb/certs/random"
        fragment_size = 1024
        include_length = yes
        check_crl = no
        cipher_list = "DEFAULT"
        ecdh_curve = "prime256v1"
    cache {
        enable = no
        lifetime = 24
        max_entries = 255
    }
    verify {
    }
    ocsp {
        enable = no
        override_cert_url = no
        url = "http://127.0.0.1/ocsp/"
    }
   }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
   ttls {
        default_eap_type = "md5"
        copy_request_to_tunnel = no
        use_tunneled_reply = no
        include_length = yes
   }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
   peap {
        default_eap_type = "mschapv2"
        copy_request_to_tunnel = no
        use_tunneled_reply = no
        proxy_tunneled_request_as_eap = yes
        soh = no
   }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
   mschapv2 {
        with_ntdomain_hack = no
        send_error = no
   }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating module "preprocess" from file /usr/pbi/freeradius-i386/etc/raddb/modules/preprocess
  preprocess {
        huntgroups = "/usr/pbi/freeradius-i386/etc/raddb/huntgroups"
        hints = "/usr/pbi/freeradius-i386/etc/raddb/hints"
        with_ascend_hack = no
        ascend_channels_per_line = 23
        with_ntdomain_hack = no
        with_specialix_jetstream_hack = no
        with_cisco_vsa_hack = no
        with_alvarion_vsa_hack = no
  }
 Module: Linked to module rlm_realm
 Module: Instantiating module "suffix" from file /usr/pbi/freeradius-i386/etc/raddb/modules/realm
  realm suffix {
        format = "suffix"
        delimiter = "@"
        ignore_default = no
        ignore_null = yes
  }
 Module: Instantiating module "ntdomain" from file /usr/pbi/freeradius-i386/etc/raddb/modules/realm
  realm ntdomain {
        format = "prefix"
        delimiter = "\"
        ignore_default = no
        ignore_null = yes
  }
 Module: Linked to module rlm_files
 Module: Instantiating module "files" from file /usr/pbi/freeradius-i386/etc/raddb/modules/files
  files {
        usersfile = "/usr/pbi/freeradius-i386/etc/raddb/users"
        acctusersfile = "/usr/pbi/freeradius-i386/etc/raddb/acct_users"
        preproxy_usersfile = "/usr/pbi/freeradius-i386/etc/raddb/preproxy_users"
        compat = "no"
  }
 Module: Linked to module rlm_checkval
 Module: Instantiating module "checkval" from file /usr/pbi/freeradius-i386/etc/raddb/modules/checkval
  checkval {
        item-name = "Calling-Station-Id"
        check-name = "Calling-Station-Id"
        data-type = "string"
        notfound-reject = no
  }
rlm_checkval: Registered name Calling-Station-Id for attribute 31
 Module: Checking preacct {...} for more modules to load
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating module "detail" from file /usr/pbi/freeradius-i386/etc/raddb/modules/detail
  detail {
        detailfile = "/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
        header = "%t"
        detailperm = 384
        dirperm = 493
        locking = no
        log_packet_header = no
  }
 Module: Instantiating module "datacounterdaily" from file /usr/pbi/freeradius-i386/etc/raddb/modules/datacounter_acct
  exec datacounterdaily {
        wait = yes
        program = "/bin/sh /usr/pbi/freeradius-i386/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} daily %{request:Acct-Input-Octets} %{request:Acct-Output-Octets}"
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Instantiating module "datacounterweekly" from file /usr/pbi/freeradius-i386/etc/raddb/modules/datacounter_acct
  exec datacounterweekly {
        wait = yes
        program = "/bin/sh /usr/pbi/freeradius-i386/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} weekly %{request:Acct-Input-Octets} %{request:Acct-Output-Octets}"
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Instantiating module "datacountermonthly" from file /usr/pbi/freeradius-i386/etc/raddb/modules/datacounter_acct
  exec datacountermonthly {
        wait = yes
        program = "/bin/sh /usr/pbi/freeradius-i386/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} monthly %{request:Acct-Input-Octets} %{request:Acct-Output-Octets}"
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Instantiating module "datacounterforever" from file /usr/pbi/freeradius-i386/etc/raddb/modules/datacounter_acct
  exec datacounterforever {
        wait = yes
        program = "/bin/sh /usr/pbi/freeradius-i386/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} forever %{request:Acct-Input-Octets} %{request:Acct-Output-Octets}"
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Linked to module rlm_radutmp
 Module: Instantiating module "radutmp" from file /usr/pbi/freeradius-i386/etc/raddb/modules/radutmp
  radutmp {
        filename = "/var/log/radutmp"
        username = "%{User-Name}"
        case_sensitive = yes
        check_with_nas = yes
        perm = 384
        callerid = yes
  }
 Module: Linked to module rlm_attr_filter
 Module: Instantiating module "attr_filter.accounting_response" from file /usr/pbi/freeradius-i386/etc/raddb/modules/attr_filter
  attr_filter attr_filter.accounting_response {
        attrsfile = "/usr/pbi/freeradius-i386/etc/raddb/attrs.accounting_response"
        key = "%{User-Name}"
        relaxed = no
  }
 Module: Checking session {...} for more modules to load
 Module: Checking pre-proxy {...} for more modules to load
 Module: Instantiating module "attr_filter.pre-proxy" from file /usr/pbi/freeradius-i386/etc/raddb/modules/attr_filter
  attr_filter attr_filter.pre-proxy {
        attrsfile = "/usr/pbi/freeradius-i386/etc/raddb/attrs.pre-proxy"
        key = "%{Realm}"
        relaxed = no
  }
 Module: Checking post-proxy {...} for more modules to load
 Module: Instantiating module "attr_filter.post-proxy" from file /usr/pbi/freeradius-i386/etc/raddb/modules/attr_filter
  attr_filter attr_filter.post-proxy {
        attrsfile = "/usr/pbi/freeradius-i386/etc/raddb/attrs"
        key = "%{Realm}"
        relaxed = no
  }
 Module: Checking post-auth {...} for more modules to load
 Module: Instantiating module "attr_filter.access_reject" from file /usr/pbi/freeradius-i386/etc/raddb/modules/attr_filter
  attr_filter attr_filter.access_reject {
        attrsfile = "/usr/pbi/freeradius-i386/etc/raddb/attrs.access_reject"
        key = "%{User-Name}"
        relaxed = no
  }
 } # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
        type = "auth"
        ipaddr = 192.168.1.1
        port = 1812
}
listen {
        type = "acct"
        ipaddr = 192.168.1.1
        port = 1813
}
listen {
        type = "status"
        ipaddr = 192.168.1.1
        port = 1816
}
Listening on authentication address 192.168.1.1 port 1812
Listening on accounting address 192.168.1.1 port 1813
Listening on status address 192.168.1.1 port 1816
Listening on proxy address 192.168.1.1 port 1814
Ready to process requests.

```was all I could capture from that command in the window

This post all after the latest snap . Again I had too only open CP and click save on the first page.
Before that all devices had access.

[Nachtfalke]

Ok, but this all seems to indicate a CP issue.
Do you have the same problem when you just reboot pfsense or is it only after a snapshot update ?

[Alan87i]

Just a reboot causes the same problem Not authorized connected pc's have full access until I save the main CP page .

[Nachtfalke]

@Alan87i:

Just a reboot causes the same problem Not authorized connected pc's have full access until I save the main CP page .

Ok, then you should probably open a new thread containing a well chosen headline like "CaptivePortal does not authenticate users after reboot against RADIUS".

Or you can open a ticket on redmine.pfsense.org