Hello list, For some time now, I've been getting some complaints that some users are getting duplicate ips and not doing any traffic .. Allocated IP: x.x.x.42 from main (did cli 00:25:22 port 622 user szc) Released IP x.x.x.42 (did cli 00:25:22 user szc) Allocated IP: x.x.x.42 from main (did cli C8:3A:35 port 25 user vii) Released IP x.x.x.42 (did cli C8:3A:35 user vii) Allocated IP: x.x.x.42 from main (did cli 00:1B:B9 port 670 user cor) Released IP x.x.x.42 (did cli 00:1B:B9 user cor) Allocated IP: x.x.x.42 from main (did cli 64:70:02 port 8 user tur) Released IP x.x.x.42 (did cli 64:70:02 user tur) Released IP x.x.x.42 (did cli C8:3A:35 user vii) Allocated IP: x.x.x.42 from main (did cli 00:26:22 port 610 user fuv) Released IP x.x.x.42 (did cli 00:26:22 user fuv) Allocated IP: x.x.x.42 from main (did cli 00:19:CB port 88 user stl) Released IP x.x.x.42 (did cli 00:19:CB user stl) Allocated IP: x.x.x.42 from main (did cli 00:14:0B port 436 user per) Released IP x.x.x.42 (did cli 00:14:0B user per) Allocated IP: x.x.x.244 from main (did cli 07:50:32 port 315 user visan Released IP x.x.x.244 (did cli 07:50:32 user visan Allocated IP: x.x.x.244 from main (did cli 37:5B:5D port 175 user cristea Released IP x.x.x.244 (did cli 37:5B:5D user cristea Allocated IP: x.x.x.244 from main (did cli 4A:69:39 port 140 user dinita Released IP x.x.x.244 (did cli 4A:69:39 user dinita Allocated IP: x.x.x.244 from main (did cli DC:D9:2F port 503 user dragusin Released IP x.x.x.244 (did cli DC:D9:2F user dragusin Allocated IP: x.x.x.244 from main (did cli 52:E2:FA port 33 user pamblica Released IP x.x.x.244 (did cli 52:E2:FA user pamblica Allocated IP: x.x.x.244 from main (did cli 95:AB:62 port 431 user ocoleanu Released IP x.x.x.244 (did cli 95:AB:62 user ocoleanu Allocated IP: x.x.x.244 from main (did cli 00:00:00 port 686 user lungu Released IP x.x.x.244 (did cli 00:00:00 user lungu Released IP x.x.x.244 (did cli 00:00:00 user lungu Allocated IP: x.x.x.244 from main (did cli 17:AA:E8 port 643 user ene Released IP x.x.x.244 (did cli 17:AA:E8 user ene Released IP x.x.x.244 (did cli 00:00:00 user lungu Allocated IP: x.x.x.244 from main (did cli EB:AF:CF port 173 user simion Released IP x.x.x.244 (did cli EB:AF:CF user simion Allocated IP: x.x.x.244 from main (did cli 15:B2:E2 port 216 user coroiu Released IP x.x.x.244 (did cli 15:B2:E2 user coroiu Allocated IP: x.x.x.244 from main (did cli 2D:AD:65 port 281 user stefan Released IP x.x.x.244 (did cli 2D:AD:65 user stefan Allocated IP: x.x.x.244 from main (did cli 03:15:27 port 545 user spita Released IP x.x.x.244 (did cli 03:15:27 user spita Allocated IP: x.x.x.244 from main (did cli 2D:AD:65 port 281 user stefan Released IP x.x.x.244 (did cli 2D:AD:65 user stefan Allocated IP: x.x.x.244 from main (did cli 2F:58:05 port 376 user simion Released IP x.x.x.244 (did cli 2F:58:05 user simion I also made a lil' script to monitor what is in radacct/radippool .. what ifconfig says and what radwho says...I can provide the source if wanted .. 2014-04-15 11:46:02 - 708 distinct ( 708 total ) framedipaddress in SQL radippool 2014-04-15 11:46:02 - Total Connected in radius SQL radacct : 380 2014-04-15 11:46:02 - Distinct IPs in radius SQL radacct: 379 2014-04-15 11:46:02 - Users sharing IP: x.x.x.x.42 - 2 - vii tur 2014-04-15 11:46:02 - There are a total of 15 reserved (SQL radreply) IPs that are connected (SQL radacct) 2014-04-15 11:46:02 - There are a total of 15 distinct reserved (SQL radreply) IPs that are connected (SQL radacct) 2014-04-15 11:46:02 - There are a total of 45 reserved IPs in SQL radreply 2014-04-15 11:46:02 - There are a total of 45 distinct reserved IPs in SQL radreply 2014-04-15 11:46:02 - There are 363 total connected users in radippool. 2014-04-15 11:46:02 - There are 363 distinct connected users in radippool. 2014-04-15 11:46:02 - There are 363 total connected user IPs in radippool. 2014-04-15 11:46:02 - There are 363 distinct connected user IPs in radippool. 2014-04-15 11:46:02 - Total IPs in radwho CLI: 380 2014-04-15 11:46:02 - Distinct IPs in radwho CLI: 379 2014-04-15 11:46:02 - Total IPs in ifconfig CLI: 380 2014-04-15 11:46:02 - Distinct IPs in ifconfig CLI: 379 2014-04-15 11:46:02 - FAIL: Total connected 15 (reserved) + 363 (radippool) != 380 (radacct) - should be 378 2014-04-15 18:18:01 - 708 distinct ( 708 total ) framedipaddress in SQL radippool 2014-04-15 18:18:01 - Total Connected in radius SQL radacct : 404 2014-04-15 18:18:01 - Distinct IPs in radius SQL radacct: 403 2014-04-15 18:18:01 - Users sharing IP: x.x.x.244 - 2 - lungu ene 2014-04-15 18:18:01 - There are a total of 13 reserved (SQL radreply) IPs that are connected (SQL radacct) 2014-04-15 18:18:01 - There are a total of 13 distinct reserved (SQL radreply) IPs that are connected (SQL radacct) 2014-04-15 18:18:01 - There are a total of 45 reserved IPs in SQL radreply 2014-04-15 18:18:01 - There are a total of 45 distinct reserved IPs in SQL radreply 2014-04-15 18:18:01 - There are 390 total connected users in radippool. 2014-04-15 18:18:01 - There are 390 distinct connected users in radippool. 2014-04-15 18:18:01 - There are 390 total connected user IPs in radippool. 2014-04-15 18:18:01 - There are 390 distinct connected user IPs in radippool. 2014-04-15 18:18:01 - Total IPs in radwho CLI: 405 2014-04-15 18:18:01 - Distinct IPs in radwho CLI: 404 2014-04-15 18:18:01 - Total IPs in ifconfig CLI: 404 2014-04-15 18:18:01 - Distinct IPs in ifconfig CLI: 403 2014-04-15 18:18:01 - FAIL: Total connected 13 (reserved) + 390 (radippool) != 404 (radacct) - should be 403 The script is ran every 2 minutes and only has selects. The "sharing" ip part goes on for some time .. I can provide full logs.. I'm running gentoo [ebuild R ] net-dialup/ppp-2.4.6:0/2.4.6 USE="pam radius -activefilter -atm -dhcp -eap-tls -gtk -ipv6" 0 kB [ebuild R ] net-dialup/rp-pppoe-3.11-r1 USE="-X" 0 kB [ebuild R ] dev-db/mysql-5.5.32 USE="community perl ssl -cluster -debug -embedded -extraengine -jemalloc -latin1 -max-idx-128 -minimal -profiling (-selinux) -static -systemtap -tcmalloc {-test}" 0 kB [ebuild R ] net-dialup/freeradius-2.2.0 USE="mysql pam readline ssl -bindist -debug (-firebird) -iodbc -kerberos -ldap -odbc -oracle -pcap -postgres -python -sqlite (-ruby%)" 0 kB The machine seems idle .. 16:06:50 up 2 days, 3:48, 2 users, load average: 0.17, 0.27, 0.39 radius is running with -xx for the past few days so I can provide logs .. 828M /var/log/radius/radius.log I've tried looking through them but can't figure out why it would do that ..
adrian.sandu@asandu.eu wrote:
For some time now, I've been getting some complaints that some users are getting duplicate ips and not doing any traffic ..
FreeRADIUS just assigns IPs. It asks the NAS to tell the user about the IP. It asks the NAS to tell FreeRADIUS when the user is done with the IP. Some NASes lie. This means that FreeRADIUS thinks the IP is unused, but the NAS has still marked it as active for that user.
radius is running with -xx for the past few days so I can provide logs .. 828M /var/log/radius/radius.log
That's good... if a little large.
I've tried looking through them but can't figure out why it would do that ..
Find an IP address which you think has been assigned to two people. Look through the logs for that IP address. You will see FreeRADIUS assigning the IP to the user. The Access-Accept will contain the IP, and a Session-Timeout. Next, look for accounting packets for that user, which contain the IP. This means that the NAS has still marked the IP as active for the user. Next, look for an accounting packet for that user which contains the IP, and is "Acct-Status-Type = Stop". If it appears, FreeRADIUS should mark that IP as free. If there is no accounting "stop", then the NAS isn't kicking the user offline. Or, it's kicking user offline and not telling FreeRADIUS. Next, look at the packets between the users original login, and then the next "Session-Timeout" seconds. You will see that the *only* references to the IP address will be in accounting packets for that user. Of course, there may be no accounting packets. After that Session-Timeout has passed, FreeRADIUS is allowed to re-use the IP. This is because the NAS is *supposed* to kick the user offline. In short, the "duplicate IP" problem is almost always the NAS. So... what NAS are you using? Is it doing RADIUS properly? Alan DeKok.
Find an IP address which you think has been assigned to two people. Look through the logs for that IP address. You will see FreeRADIUS assigning the IP to the user. The Access-Accept will contain the IP, and a Session-Timeout.
I wish I wouldn't have a timeout though .. anyhow The only thing with "Access-Accept" in the radius.log file I see is the result of [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
Next, look for accounting packets for that user, which contain the IP. This means that the NAS has still marked the IP as active for the user.
How would those look ?
Next, look for an accounting packet for that user which contains the IP, and is "Acct-Status-Type = Stop". If it appears, FreeRADIUS should mark that IP as free.
PPPoE radius # grep -i "Acct-Status-Type" radius.log Yells nothing .. for noone .. I might not have it enabled ?
So... what NAS are you using? Is it doing RADIUS properly?
I'm using rp-pppoe with the radius plugin http://www.roaringpenguin.com/products/pppoe I think it's doing it right ..
adrian.sandu@asandu.eu wrote:
I wish I wouldn't have a timeout though .. anyhow
You don't need a Session-Timeout. You *do* need a NAS which works.
The only thing with "Access-Accept" in the radius.log file I see is the result of [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
No... that's not Access-Accept. If you're running in debugging mode, you'll see Access-Accept, followed by a series of attributes. It should be *very* obvious.
Next, look for accounting packets for that user, which contain the IP. This means that the NAS has still marked the IP as active for the user.
How would those look ?
Look for the IP address. If the NAS is sending accounting packets, the IP will show up in the logs.
Next, look for an accounting packet for that user which contains the IP, and is "Acct-Status-Type = Stop". If it appears, FreeRADIUS should mark that IP as free.
PPPoE radius # grep -i "Acct-Status-Type" radius.log Yells nothing .. for noone .. I might not have it enabled ?
Then accounting isn't enabled. Enable it on the NAS. Alan DeKok.
The only thing with "Access-Accept" in the radius.log file I see is the result of [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
No... that's not Access-Accept. If you're running in debugging mode, you'll see Access-Accept, followed by a series of attributes. It should be *very* obvious.
Ok, well .. I don't see it ! :| Can you give me an example ?
Next, look for accounting packets for that user, which contain the IP. This means that the NAS has still marked the IP as active for the user.
How would those look ?
Look for the IP address. If the NAS is sending accounting packets, the IP will show up in the logs.
I am looking .. I don't get it .. I wish there were an easy way to track the IP ..
Then accounting isn't enabled. Enable it on the NAS.
Dang. http://linux.die.net/man/8/pppd-radius Doesn't tell anything about it :\ Here's a link to a rather long post ( manually copy/pasted everything I could (tried to keep the consistency )). I also wish there was a tool to easily mask sensitive data from the log .. http://pastebin.com/9bLNBBZi [asandu@asandu3 ~]$ grep -iE "^(allocated|released) ip" log | grep x.x.x.244 Allocated IP: x.x.x.244 from main (did cli 00:16:76 port 33 user pav) Released IP x.x.x.244 (did cli 00:16:76 user pav) Allocated IP: x.x.x.244 from main (did cli 00:0B:6A port 431 user ocv) Released IP x.x.x.244 (did cli 00:0B:6A user ocv) Allocated IP: x.x.x.244 from main (did cli 00:0C:61 port 686 user lum) Released IP x.x.x.244 (did cli 00:0C:61 user lum) Released IP x.x.x.244 (did cli 00:0C:61 user lum) Allocated IP: x.x.x.244 from main (did cli 00:19:21 port 643 user enm) Released IP x.x.x.244 (did cli 00:19:21 user enm) Released IP x.x.x.244 (did cli 00:0C:61 user lum) Allocated IP: x.x.x.244 from main (did cli 00:0F:EA port 173 user sii) Released IP x.x.x.244 (did cli 00:0F:EA user sii) Allocated IP: x.x.x.244 from main (did cli D8:EB:97 port 216 user cog) Released IP x.x.x.244 (did cli D8:EB:97 user cog)
Adrian, Try setting radippool maximum-timout 5 times greater then your acct-interim-update. -- Roney Eduardo
Try setting radippool maximum-timout 5 times greater then your acct-interim-update.
Can you tell me what you're refering to. I don't see any references to "maximum-timeout" or "acct-interim-update" in anything in my /etc/raddb/ folder... acct-interim-update = Acct-Interim-Interval in the radreply table for each user ? ( I don't have any set now )
2014-04-18 11:14 GMT-03:00 <adrian.sandu@asandu.eu>:
Can you tell me what you're refering to. I don't see any references to "maximum-timeout" or "acct-interim-update" in anything in my /etc/raddb/ folder...
"maximum-timout" is in /etc/raddb/modules/ippool (if that's what you're using, instead of sqlippool).
acct-interim-update = Acct-Interim-Interval in the radreply table for each user ? ( I don't have any set now )
Yes, but instead of having one per user, you can have one per group in ragroupreply table.
participants (3)
-
adrian.sandu@asandu.eu -
Alan DeKok -
Rôney Eduardo