I've been having issues sending to the list, so apologies if this is dup.
I've got some weirdness with freeradius 1.0.1 (same results
in previous versions). Test systems are x86_64 and i386 Fedora Core 2
machines (2.6.8.1). Same tests on older redhat9 machine (2.6.4) do not have
the same issue.
My users entry looks like:
DEFAULT Auth-Type := Accept
Exec-Program-Wait = "/etc/raddb/scripts/pre_auth.sh",
Fall-Through = Yes
There are no other authentication mechanisms enabled, all requests go to
pre_auth.sh. The script is configured to only exit 0 (although I get
identical results when rejecting requests with exit 1) and pass attributes.
Same results w/o attributes.
This issue only happens when running in standard mode, in debug -x or debug
-xx mode. The problem can be duplicated over and over on various platforms.
The problem does not happen in -X debug mode. Problem also does not happen
in single thread mode.
When sending test radius packets it will authenticate the first always, then
depending on the frequency of the incoming packets it will hang usually once
they are sent at a rate of apx 1+/second. Sending packets continuously at 1
each 2 seconds it will never have any problem.
It appears to be in the following entry that it is hanging right before it
gets to the "Exec-Program: returned: 0" section. Almost as if it's not
catching the return value of the external program. Later (10-15 seconds) it
drops that client as unresponsive. Attaching 2 -xx debug reports, the first
is the request which bombs, the 2nd is a good request.
Any help in further debugging or solving this issue is greatly appreciated.
###### REQUEST WHICH BOMBS ######
Going to the next request
Thread 7 waiting to be assigned a request
rad_recv: Access-Request packet from host 63.228.227.6:2300, id=67,
length=53
Waking up in 2 seconds...
Thread 8 got semaphore
Thread 8 handling request 6, (1 handled so far)
User-Name = "[EMAIL PROTECTED]"
User-Password = "xxxxx"
rad_rmspace_pair: User-Name now '[EMAIL PROTECTED]'
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 6
modcall[authorize]: module "preprocess" returns ok for request 6
modcall[authorize]: module "attr_filter" returns noop for request 6
rlm_realm: No '#' in User-Name = "[EMAIL PROTECTED]", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "prefix" returns noop for request 6
rlm_realm: Looking up realm "visp.net" for User-Name = "[EMAIL PROTECTED]"
rlm_realm: No such realm "visp.net"
modcall[authorize]: module "suffix" returns noop for request 6
users: Matched DEFAULT at 36
modcall[authorize]: module "files" returns ok for request 6
modcall: group authorize returns ok for request 6
rad_check_password: Found Auth-Type Accept
rad_check_password: Auth-Type = Accept, accepting the user
radius_xlat: '/etc/raddb/scripts/pre_auth.sh'
Exec-Program: /etc/raddb/scripts/pre_auth.sh
Re-wait 2
Exec-Program output: Idle-Timeout = 1140, Session-Timeout = 28800,
Service-Type = Framed-User, Framed-IP-Address = 255.255.255.254,
Framed-Protocol = PPP, Simultaneous-Use = 1,
Exec-Program-Wait: value-pairs: Idle-Timeout = 1140, Session-Timeout =
28800, Service-Type = Framed-User, Framed-IP-Address = 255.255.255.254,
Framed-Protocol = PPP, Simultaneous-Use = 1,
--- Walking the entire request list ---
Cleaning up request 0 ID 61 with timestamp 416c1c9c
Cleaning up request 1 ID 62 with timestamp 416c1c9c
Cleaning up request 2 ID 63 with timestamp 416c1c9c
Waking up in 1 seconds...
Threads: total/active/spare threads = 15/1/14
--- Walking the entire request list ---
Cleaning up request 3 ID 64 with timestamp 416c1c9d
Cleaning up request 4 ID 65 with timestamp 416c1c9d
Cleaning up request 5 ID 66 with timestamp 416c1c9d
Waking up in 5 seconds...
--- Walking the entire request list ---
Waking up in 5 seconds...
--- Walking the entire request list ---
Waking up in 5 seconds...
--- Walking the entire request list ---
WARNING: Unresponsive child (id 1145158576) for request 6
Server rejecting request 6.
Sending Access-Reject of id 67 to 63.228.227.6:2300
Waking up in 5 seconds...
--- Walking the entire request list ---
#### STRACE OUTPUT at time of error ####
radius_xlat: '/etc/raddb/scripts/pre_auth.sh'
Exec-Program: /etc/raddb/scripts/pre_auth.sh
Exec-Program output: Idle-Timeout = 1140, Session-Timeout = 28800,
Service-Type = Framed-User, Framed-IP-Address = 255.255.255.254,
Framed-Protocol = PPP, Simultaneous-Use = 1,
Exec-Program-Wait: value-pairs: Idle-Timeout = 1140, Session-Timeout =
28800, Service-Type = Framed-User, Framed-IP-Address = 255.255.255.254,
Framed-Protocol = PPP, Simultaneous-Use = 1,
) = 0 (Timeout)
time(NULL) = 1097605809
time(NULL) = 1097605809
write(1, "--- Walking the entire request l"..., 40--- Walking the entire
request list ---
) = 40
###### REQUEST WHICH WORKS PROPERLY ######
Thread 6 waiting to be assigned a request
Re-wait 2
rad_recv: Access-Request packet from host 63.228.227.6:2299, id=66,
length=53
Waking up in 2 seconds...
Thread 7 got semaphore
Thread 7 handling request 5, (1 handled so far)
User-Name = "[EMAIL PROTECTED]"
User-Password = "xxxxx"
rad_rmspace_pair: User-Name now '[EMAIL PROTECTED]'
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 5
modcall[authorize]: module "preprocess" returns ok for request 5
modcall[authorize]: module "attr_filter" returns noop for request 5
rlm_realm: No '#' in User-Name = "[EMAIL PROTECTED]", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "prefix" returns noop for request 5
rlm_realm: Looking up realm "visp.net" for User-Name = "[EMAIL PROTECTED]"
rlm_realm: No such realm "visp.net"
modcall[authorize]: module "suffix" returns noop for request 5
users: Matched DEFAULT at 36
modcall[authorize]: module "files" returns ok for request 5
modcall: group authorize returns ok for request 5
rad_check_password: Found Auth-Type Accept
rad_check_password: Auth-Type = Accept, accepting the user
radius_xlat: '/etc/raddb/scripts/pre_auth.sh'
Exec-Program: /etc/raddb/scripts/pre_auth.sh
Exec-Program output: Idle-Timeout = 1140, Session-Timeout = 28800,
Service-Type = Framed-User, Framed-IP-Address = 255.255.255.254,
Framed-Protocol = PPP, Simultaneous-Use = 1,
Exec-Program-Wait: value-pairs: Idle-Timeout = 1140, Session-Timeout =
28800, Service-Type = Framed-User, Framed-IP-Address = 255.255.255.254,
Framed-Protocol = PPP, Simultaneous-Use = 1,
Exec-Program: returned: 0
Login OK: [EMAIL PROTECTED]/xxxxx] (from client natewkstation port 0)
Sending Access-Accept of id 66 to 63.228.227.6:2299
Idle-Timeout = 1140
Session-Timeout = 28800
Service-Type = Framed-User
Framed-IP-Address = 255.255.255.254
Framed-Protocol = PPP
Finished request 5
----------------------------------
Nathan Miller
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
