[prev in list] [next in list] [prev in thread] [next in thread]
List: cistron-radius
Subject: AGAIN: Please can s.o. explain?
From: The light in the dark <sijaiko () netplus ! bg>
Date: 1998-12-17 20:00:40
[Download RAW message or body]
I have BIG problems with RADIUS server (or client).
My NAS is BayNetworks Versalar RAC 8000.
I do get LOTS of dupes, out of orders and such packets.
I'm putting some logs. Some data (IPs and groups) has been cut off
for... hmmm... security reasons. (*shrug* got my boss, you know :( )
This is part of a "hanging" day :(
The NAS sends completely OK AUTH packets, but s.th. is wrong with
the ACCOUNTING. People get authenticated, then the NAS sends the login
auth packet for the user skala, with Acct-Delay-Time recalculated, BUT for
one and the same "skala" session.
The "skala" user is just a user. They log in, and then something
happens. If s.o. sees the problem, please help.
This is "last -f /var/log/radwtmp". Just a couple of lines:
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (23:59)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (23:59)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (23:59)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (23:59)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (23:59)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (23:59)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (23:59)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
skala 002:grave 192.168.110.8 Sat Dec 12 15:30 - 15:30 (00:00)
The 00:00 sessions are +1 or +0 seconds long.
The 23:59 sessions are -1 seconds long.
Here is some "raw" data from the /var/log/radwtmp for the same
period. The Time field value, expressed in calendar date is
1998 Sat Dec 12 15:30
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fed User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fed User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fed User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fed User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fed User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726ff0 User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fed User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fed User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fed User: skala
Type: 7 Line: 002:grave ID: P Time: 36726fec User: skala
This is the "detail" file. Just a couple of packets to show what's
going on:
Sat Dec 12 23:16:18 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 28029
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913497378
Request-Authenticator = Verified
Sat Dec 12 23:21:19 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 28330
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913497679
Request-Authenticator = Verified
Sat Dec 12 23:26:20 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 28631
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913497980
Request-Authenticator = Verified
Sat Dec 12 23:31:21 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 28932
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913498281
Request-Authenticator = Verified
Sat Dec 12 23:36:22 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 29233
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913498582
Request-Authenticator = Verified
Sat Dec 12 23:41:23 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 29534
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913498883
Request-Authenticator = Verified
Sat Dec 12 23:46:24 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 29835
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913499184
Request-Authenticator = Verified
Sat Dec 12 23:51:25 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 30136
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913499485
Request-Authenticator = Verified
Sat Dec 12 23:56:26 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 30437
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913499786
Request-Authenticator = Verified
.....................
At about every 300(+-1) seconds the server receives a packet, with
the timestamp moves 300(+-1) seconds, and the Acct-Delay-Time is 300(+-1)
seconds more. So I get a /var/log/radwtmp like the one shown at the middle
of this message.
Here I reboot the NAS:
Look at the next Acct-Delay-Time :(
.....................
Tue Dec 15 09:27:47 1998
Acct-Status-Type = Start
Acct-Session-Id = "d20d02ea"
Acct-Delay-Time = 237523
NAS-Port-Id = 2
NAS-Port-Type = Async
User-Name = "skala"
Service-Type = Framed-User
Framed-Protocol = PPP
Called-Station-Id = "2"
Connect-Info = "9600 9600 V.34"
Acct-Authentic = RADIUS
Framed-IP-Address = 192.168.110.8
Timestamp = 913706867
Request-Authenticator = Verified
Tue Dec 15 09:30:07 1998
Acct-Status-Type = Accounting-Off
Acct-Session-Id = "d20d0000"
Acct-Delay-Time = 1
Timestamp = 913707007
Request-Authenticator = Verified
Tue Dec 15 09:30:49 1998
Acct-Status-Type = Accounting-On
Acct-Session-Id = "52050001"
Acct-Delay-Time = 1
Timestamp = 913707049
Request-Authenticator = Verified
.................
Everything goes OK for a couple of days. Than again :(
While this lasts, I get lots of this lines :
Error: Accounting: login: entry for NAS grave port 2 out of order
Error: Accounting: login: entry for NAS grave port 2 out of order
Error: Accounting: login: entry for NAS grave port 2 out of order
Error: Accounting: login: entry for NAS grave port 2 out of order
Error: Accounting: login: entry for NAS grave port 2 out of order
Error: Accounting: login: entry for NAS grave port 2 out of order
With about 5min (300 +-1 secs) time intervals.
When a user logs in I get this:
Info: Exec-Program: /home/sijaiko/Verify/check_time fan
Info: Exec-Program-Pars: decoding answer. \
Info: Exec-Program-Pars: Session-Timeout = 432000 . \ Exec-Program-Pars
Info: Exec-Program-Pars: decoded... adding. / Debugging output.
Info: Exec-Program-Pars: answer added. /
Info: Exec-Program: returned: 0
Auth: Login OK: [fan] (from nas grave)
The user is authenticated OK, but I don't get ACCT packet. I get a
packet after a while. Well, I get an ACCT packet every 5 minutes, but not
for this user, not for this line, not for this time. Im getting a single
packet repeated every 5 minutes...
Any suggestions?
Sijaiko.
_/_/ _/_/_/ _/ _/_/_/ /~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~\
_/ _/ _/ _/ _/ _/ | He, who controls the past, |
_/ _/ _/ _/ _/ | commands the future... |
_/ _/ _/ _/ _/ _/ _/ | He, who commands the future, |
_/_/ _/_/_/ /_/_/ _/_/_/ | conquers the past... |
``` ````` ```` ````` \______________________________/
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic