[RADIATOR] weird AuthBy Radius problem

Alexander Hartmaier alexander.hartmaier at t-systems.at
Thu Jul 1 02:36:15 CDT 2010


Hi Hugh,

thanks for your hint, you were totally right!
The dns reverse lookup caused by %C used for the AuthLog file does take
that much time from one of our bind dns servers, we're investigating now
why.

I've replaced it with %c and the problem is gone.

Maybe the radiator internals should be changed so logging happens after
sending the reply to the client?

That's again a case where the blocking nature of radiator causes severe
problems...

-- 
Best regards, Alex


Am Donnerstag, den 01.07.2010, 07:33 +0200 schrieb Hugh Irvine:
> Hello Alex -
> 
> I have not been able to reproduce this problem here.
> 
> The only thing I can think of is some DNS lookup (or similar) that is taking a long time.
> 
> Is there any more information you can provide?
> 
> regards
> 
> Hugh
> 
> 
> On 1 Jul 2010, at 01:28, Alexander Hartmaier wrote:
> 
> > Hi,
> > 
> > I'm fighting a Radiator problem since today where Radiator sends the tacacs+ reply to the client 20 seconds after receiving an radius reply from another Radiator server.
> > 
> > That's our config:
> > 
> > <ServerTACACSPLUS>
> >     Key foo
> >     Port 49
> >     AuthorizationTimeout 600
> >     IdleTimeout 600
> > 
> >     # Group attribute 
> >     GroupMemberAttr Class
> > 
> >     PreHandlerHook file:"%D/tacacs_client_identifier.pl"
> > 
> >     AuthorizeGroup bar      permit .*
> > </ServerTACACSPLUS>
> > 
> > <AuthBy RADIUS>
> >     Identifier tsa_radius
> > 
> >     Host radius1.our-fqdn.org
> >     Host radius2.our-fqdn.org
> >     Secret radius-secret
> >     AuthPort 1645
> >     #AcctPort 1646
> >     NoForwardAccounting
> >     Retries 0
> >     RetryTimeout 3
> > </AuthBy>
> > 
> > <Handler OSC-Client-Identifier=tacacs_clients, Service-Type=Login-User>
> >     AuthByPolicy ContinueUntilAccept
> >     # don't use a session database
> >     SessionDatabase none
> > 
> >     # no accounting should match that Handler
> > 
> >     <AuthBy FILE>
> >         Filename %D/user_db/users.tacacs
> >     </AuthBy>
> > 
> >     AuthBy tsa_radius
> > 
> >     <AuthLog FILE>
> >         Identifier tacacs_login
> >         Filename %L/tacacs-login.authlog
> > 
> >         SuccessFormat %l:%C:%U:****:OK
> >         FailureFormat %l:%C:%U:****:FAIL
> > 
> >         LogSuccess 1
> >         LogFailure 1
> >     </AuthLog>
> > </Handler>
> > 
> > # accounting
> > <Handler OSC-Client-Identifier=tacacs_clients>
> >     # don't use a session database
> >     SessionDatabase none
> > 
> >     # save accounting to file
> >     AcctLogFileName %L/accounting/%c/%Y/%m/%Y-%m-%d-%c.log
> > 
> >     # TBD
> >     # AcctLogFileFormat %{Timestamp} %{User-Name}
> > </Handler>
> > 
> > The hook tacacs_client_identifier puts the tacacs client identifier in the OSC-Client-Identifier radius attribute for later use (from goodies).
> > 
> > This is a trace 4 log showing the problem:
> > 
> > Wed Jun 30 17:13:43 2010: DEBUG: New TacacsplusConnection created for 172.16.1.1:49092
> > Wed Jun 30 17:13:43 2010: DEBUG: TacacsplusConnection request 192, 1, 1, 0, 160897109, 33
> > Wed Jun 30 17:13:43 2010: DEBUG: TacacsplusConnection Authentication START 1, 1, 1 for username, 593920, 192.168.1.1
> > Wed Jun 30 17:13:43 2010: DEBUG: TacacsplusConnection Authentication REPLY 5, 1, Password: ,  
> > Wed Jun 30 17:13:43 2010: DEBUG: TacacsplusConnection request 192, 1, 3, 0, 160897109, 14
> > Wed Jun 30 17:13:43 2010: DEBUG: TacacsplusConnection Authentication CONTINUE 0, **obscured**, 
> > Wed Jun 30 17:13:43 2010: DEBUG: TACACSPLUS derived Radius request packet dump:
> > Code:       Access-Request
> > Identifier: UNDEF
> > Authentic:  <202><192><17><134><158>A<163><229><154><225><234><1><171><169><211><29>
> > Attributes:
> > NAS-IP-Address = 172.16.1.1
> > NAS-Port-Id = "593920"
> > Calling-Station-Id = "192.168.1.1"
> > Service-Type = Login-User
> > NAS-Identifier = "TACACS"
> > User-Name = "username"
> > User-Password = **obscured**
> > OSC-Version-Identifier = "192"
> > 
> > Wed Jun 30 17:13:43 2010: DEBUG: Hook tacacs_client_identifier called
> > Wed Jun 30 17:13:43 2010: DEBUG: Hook tacacs_client_identifier searching for client <172.16.1.1>
> > Wed Jun 30 17:13:43 2010: DEBUG: Hook tacacs_client_identifier got client ident <tacacs_clients>
> > Wed Jun 30 17:13:43 2010: DEBUG: Handling request with Handler 'OSC-Client-Identifier=tacacs_clients, Service-Type=Login-User', Identifier ''
> > Wed Jun 30 17:13:43 2010: DEBUG:  Deleting session for username, 172.16.1.1, 
> > Wed Jun 30 17:13:43 2010: DEBUG: Handling with Radius::AuthFILE: 
> > Wed Jun 30 17:13:43 2010: DEBUG: Radius::AuthFILE looks for match with username [username]
> > Wed Jun 30 17:13:43 2010: DEBUG: Radius::AuthFILE REJECT: No such user: username [username]
> > Wed Jun 30 17:13:43 2010: DEBUG: AuthBy FILE result: REJECT, No such user
> > Wed Jun 30 17:13:43 2010: DEBUG: Handling with Radius::AuthRADIUS
> > Wed Jun 30 17:13:43 2010: DEBUG: Packet dump:
> > *** Sending to 192.168.2.1 port 1645 ....
> > Code:       Access-Request
> > Identifier: 3
> > Authentic:  <202><192><17><134><158>A<163><229><154><225><234><1><171><169><211><29>
> > Attributes:
> > NAS-IP-Address = 172.16.1.1
> > NAS-Port-Id = "593920"
> > Calling-Station-Id = "192.168.1.1"
> > Service-Type = Login-User
> > NAS-Identifier = "TACACS"
> > User-Name = "username"
> > User-Password = 8<181><210><234>cJ0<226><141><169><240><28>\<252><135><210>
> > OSC-Version-Identifier = "192"
> > OSC-Client-Identifier = "tacacs_clients"
> > 
> > Wed Jun 30 17:13:43 2010: DEBUG: AuthBy RADIUS result: IGNORE, 
> > Wed Jun 30 17:13:43 2010: DEBUG: Received reply in AuthRADIUS for req 3 from 192.168.2.1:1645
> > Wed Jun 30 17:13:43 2010: DEBUG: Packet dump:
> > *** Received from 192.168.2.1 port 1645 ....
> > Code:       Access-Accept
> > Identifier: 3
> > Authentic:  <247><184><242><205><231>U<177>F<167>6O)a<165>'<222>
> > Attributes:
> > Class = "bar"
> > 
> > Wed Jun 30 17:13:43 2010: DEBUG: Access accepted for username
> > 
> > ### here is the 20 second delay ###
> > 
> > Wed Jun 30 17:14:03 2010: DEBUG: Packet dump:
> > *** Reply to TACACSPLUS request:
> > Code:       Access-Accept
> > Identifier: UNDEF
> > Authentic:  <202><192><17><134><158>A<163><229><154><225><234><1><171><169><211><29>
> > Attributes:
> > Class = "bar"
> > 
> > Wed Jun 30 17:14:03 2010: DEBUG: TacacsplusConnection result Access-Accept
> > Wed Jun 30 17:14:03 2010: DEBUG: TacacsplusConnection Authentication REPLY 1, 0, ,  
> > Wed Jun 30 17:14:03 2010: DEBUG: TacacsplusConnection disconnected from 172.16.1.1:49092
> > 
> > 
> > -- 
> > Best regards, Alex
> > 
> > 
> > 
> > 
> > *"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*
> > T-Systems Austria GesmbH Rennweg 97-99, 1030 Wien
> > Handelsgericht Wien, FN 79340b
> > *"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*
> > Notice: This e-mail contains information that is confidential and may be privileged.
> > If you are not the intended recipient, please notify the sender and then
> > delete this e-mail immediately.
> > *"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*
> > _______________________________________________
> > radiator mailing list
> > radiator at open.com.au
> > http://www.open.com.au/mailman/listinfo/radiator
> 
> 
> 
> NB: 
> 
> Have you read the reference manual ("doc/ref.html")?
> Have you searched the mailing list archive (www.open.com.au/archives/radiator)?
> Have you had a quick look on Google (www.google.com)?
> Have you included a copy of your configuration file (no secrets), 
> together with a trace 4 debug showing what is happening?
> 



More information about the radiator mailing list