[RADIATOR] weird AuthBy Radius problem

Wed Jun 30 10:28:13 CDT 2010

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.
*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*"*
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://www.open.com.au/pipermail/radiator/attachments/20100630/efdc7da2/attachment.html 