rad_recv: Access-Request packet from host 2001:0:0:1::175 port 21812, id=0, length=63
        User-Name = "vikas"
        User-Password = "password"
        NAS-IP-Address = 0x20010000000000010000000000000175
Fri Aug 31 15:20:10 2007 : Debug:   Processing the authorize section of radiusd.conf
Fri Aug 31 15:20:10 2007 : Debug: +- entering group authorize
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[preprocess] returns ok
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 0
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[chap] returns noop
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 0
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[mschap] returns noop
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling unix (rlm_unix) for request 0
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from unix (rlm_unix) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[unix] returns notfound
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 0
Fri Aug 31 15:20:10 2007 : Debug:     rlm_realm: No '@' in User-Name = "vikas", looking up realm NULL
Fri Aug 31 15:20:10 2007 : Debug:     rlm_realm: No such realm "NULL"
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[suffix] returns noop
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 0
Fri Aug 31 15:20:10 2007 : Debug:   rlm_eap: No EAP-Message, not doing EAP
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[eap] returns noop
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 0Fri Aug 31 15:20:10 2007 : Debug:     users: Matched entry vikas at line 93
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[files] returns ok
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling expiration (rlm_expiration) for request 0
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from expiration (rlm_expiration) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[expiration] returns noop
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling logintime (rlm_logintime) for request 0
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from logintime (rlm_logintime) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[logintime] returns noop
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 0
Fri Aug 31 15:20:10 2007 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[pap] returns noop
Fri Aug 31 15:20:10 2007 : Debug: +- group authorize returns ok
Fri Aug 31 15:20:10 2007 : Debug: auth: No authenticate method (Auth-Type) configuration found for the request: Rejecting the user
Fri Aug 31 15:20:10 2007 : Debug: auth: Failed to validate the user.
Fri Aug 31 15:20:10 2007 : Debug:   Found Post-Auth-Type Reject
Fri Aug 31 15:20:10 2007 : Debug:   Processing the post-auth section of radiusd.conf
Fri Aug 31 15:20:10 2007 : Debug: +- entering group REJECT
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 0
Fri Aug 31 15:20:10 2007 : Debug: radius_xlat:  'vikas'
Fri Aug 31 15:20:10 2007 : Debug:  attr_filter: Matched entry DEFAULT at line 11
Fri Aug 31 15:20:10 2007 : Debug:   modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 0
Fri Aug 31 15:20:10 2007 : Debug: ++[attr_filter.access_reject] returns updated
Fri Aug 31 15:20:10 2007 : Debug: +- group REJECT returns updated
Fri Aug 31 15:20:10 2007 : Debug: Delaying reject of request 0 for 1 seconds
Fri Aug 31 15:20:10 2007 : Debug: Going to the next request
Fri Aug 31 15:20:11 2007 : Debug: Sending delayed reject for request 0
Sending Access-Reject of id 0 to 2001:0:0:1::175 port 21812
Fri Aug 31 15:20:11 2007 : Debug: Waking up in 4 seconds...
rad_recv: Access-Request packet from host 2001:0:0:1::175 port 21812, id=0, length=63
Fri Aug 31 15:20:13 2007 : Debug: Cleaning up request 0 ID 0 with timestamp +8
        User-Name = "vikas"
        User-Password = "password"
        NAS-IP-Address = 0x20010000000000010000000000000175
Fri Aug 31 15:20:13 2007 : Debug:   Processing the authorize section of radiusd.conf
Fri Aug 31 15:20:13 2007 : Debug: +- entering group authorize
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[preprocess] returns ok
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 1
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[chap] returns noop
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 1
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[mschap] returns noop
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling unix (rlm_unix) for request 1
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from unix (rlm_unix) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[unix] returns notfound
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 1
Fri Aug 31 15:20:13 2007 : Debug:     rlm_realm: No '@' in User-Name = "vikas", looking up realm NULL
Fri Aug 31 15:20:13 2007 : Debug:     rlm_realm: No such realm "NULL"
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[suffix] returns noop
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 1
Fri Aug 31 15:20:13 2007 : Debug:   rlm_eap: No EAP-Message, not doing EAP
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[eap] returns noop
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 1Fri Aug 31 15:20:13 2007 : Debug:     users: Matched entry vikas at line 93
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[files] returns ok
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling expiration (rlm_expiration) for request 1
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from expiration (rlm_expiration) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[expiration] returns noop
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling logintime (rlm_logintime) for request 1
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from logintime (rlm_logintime) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[logintime] returns noop
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 1
Fri Aug 31 15:20:13 2007 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[pap] returns noop
Fri Aug 31 15:20:13 2007 : Debug: +- group authorize returns ok
Fri Aug 31 15:20:13 2007 : Debug: auth: No authenticate method (Auth-Type) configuration found for the request: Rejecting the user
Fri Aug 31 15:20:13 2007 : Debug: auth: Failed to validate the user.
Fri Aug 31 15:20:13 2007 : Debug:   Found Post-Auth-Type Reject
Fri Aug 31 15:20:13 2007 : Debug:   Processing the post-auth section of radiusd.conf
Fri Aug 31 15:20:13 2007 : Debug: +- entering group REJECT
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 1
Fri Aug 31 15:20:13 2007 : Debug: radius_xlat:  'vikas'
Fri Aug 31 15:20:13 2007 : Debug:  attr_filter: Matched entry DEFAULT at line 11
Fri Aug 31 15:20:13 2007 : Debug:   modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 1
Fri Aug 31 15:20:13 2007 : Debug: ++[attr_filter.access_reject] returns updated
Fri Aug 31 15:20:13 2007 : Debug: +- group REJECT returns updated
Fri Aug 31 15:20:13 2007 : Debug: Delaying reject of request 1 for 1 seconds
Fri Aug 31 15:20:13 2007 : Debug: Going to the next request
Fri Aug 31 15:20:14 2007 : Debug: Sending delayed reject for request 1
Sending Access-Reject of id 0 to 2001:0:0:1::175 port 21812
Fri Aug 31 15:20:14 2007 : Debug: Waking up in 4 seconds...
rad_recv: Access-Request packet from host 2001:0:0:1::175 port 21812, id=0, length=63
Fri Aug 31 15:20:17 2007 : Debug: Cleaning up request 1 ID 0 with timestamp +11
        User-Name = "vikas"
        User-Password = "password"
        NAS-IP-Address = 0x20010000000000010000000000000175
Fri Aug 31 15:20:17 2007 : Debug:   Processing the authorize section of radiusd.conf
Fri Aug 31 15:20:17 2007 : Debug: +- entering group authorize
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[preprocess] returns ok
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 2
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[chap] returns noop
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 2
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[mschap] returns noop
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling unix (rlm_unix) for request 2
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from unix (rlm_unix) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[unix] returns notfound
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 2
Fri Aug 31 15:20:17 2007 : Debug:     rlm_realm: No '@' in User-Name = "vikas", looking up realm NULL
Fri Aug 31 15:20:17 2007 : Debug:     rlm_realm: No such realm "NULL"
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[suffix] returns noop
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 2
Fri Aug 31 15:20:17 2007 : Debug:   rlm_eap: No EAP-Message, not doing EAP
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[eap] returns noop
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 2Fri Aug 31 15:20:17 2007 : Debug:     users: Matched entry vikas at line 93
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[files] returns ok
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling expiration (rlm_expiration) for request 2
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from expiration (rlm_expiration) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[expiration] returns noop
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling logintime (rlm_logintime) for request 2
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from logintime (rlm_logintime) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[logintime] returns noop
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 2
Fri Aug 31 15:20:17 2007 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[pap] returns noop
Fri Aug 31 15:20:17 2007 : Debug: +- group authorize returns ok
Fri Aug 31 15:20:17 2007 : Debug: auth: No authenticate method (Auth-Type) configuration found for the request: Rejecting the user
Fri Aug 31 15:20:17 2007 : Debug: auth: Failed to validate the user.
Fri Aug 31 15:20:17 2007 : Debug:   Found Post-Auth-Type Reject
Fri Aug 31 15:20:17 2007 : Debug:   Processing the post-auth section of radiusd.conf
Fri Aug 31 15:20:17 2007 : Debug: +- entering group REJECT
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 2
Fri Aug 31 15:20:17 2007 : Debug: radius_xlat:  'vikas'
Fri Aug 31 15:20:17 2007 : Debug:  attr_filter: Matched entry DEFAULT at line 11
Fri Aug 31 15:20:17 2007 : Debug:   modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 2
Fri Aug 31 15:20:17 2007 : Debug: ++[attr_filter.access_reject] returns updated
Fri Aug 31 15:20:17 2007 : Debug: +- group REJECT returns updated
Fri Aug 31 15:20:17 2007 : Debug: Delaying reject of request 2 for 1 seconds
Fri Aug 31 15:20:17 2007 : Debug: Going to the next request
Fri Aug 31 15:20:18 2007 : Debug: Sending delayed reject for request 2
Sending Access-Reject of id 0 to 2001:0:0:1::175 port 21812
Fri Aug 31 15:20:18 2007 : Debug: Waking up in 4 seconds...
Fri Aug 31 15:20:23 2007 : Debug: Cleaning up request 2 ID 0 with timestamp +15
Fri Aug 31 15:20:23 2007 : Debug: Nothing to do.  Sleeping until we see a request.