Rejected proxy requests not making it to the client
I have a setup where we have three distinct OTP services, one by the organization and 2 specific to our group. Users can choose which service they want to use and this is done by membership in a netgroup (an rlm_perl script looks up the user to see what netgroup they belong to). We have proxy servers that all the clients talk to and their purpose is to determine which upstream OTP service to authenticate a user against and proxy the requests there. I'm seeing strange behavior when a user types their password incorrectly in that the reject never makes it all the way to the client and on the server I see the following on the server: Tue Jul 2 10:39:04 2013 : Error: WARNING: Unresponsive child for request 0, in component <core> module <thread> Tue Jul 2 10:39:05 2013 : Info: WARNING: Child is hung for request 0 in component <core> module <thread>. Tue Jul 2 10:39:06 2013 : Info: WARNING: Child is hung for request 0 in component <core> module <thread>. Tue Jul 2 10:39:09 2013 : Info: WARNING: Child is hung for request 0 in component <core> module <thread>. Tue Jul 2 10:39:12 2013 : Info: WARNING: Child is hung for request 0 in component <core> module <thread>. Tue Jul 2 10:39:17 2013 : Info: WARNING: Child is hung for request 0 in component <core> module <thread>. Tue Jul 2 10:39:25 2013 : Info: WARNING: Child is hung for request 0 in component <core> module <thread>. Tue Jul 2 10:39:36 2013 : Info: WARNING: Child is hung for request 0 in component <core> module <thread>. ... The upstream server does get the request, send the reject back to the proxy and the proxy receives the reject but doesn't seem to send the reject back to the client. When the user types the password successfully everything works fine - the client gets an OK and none of the hung request errors show up. A debug log of one of these failed sessions is at http://pastebin.com/8n7snaBV. Any ideas what might be going on?
Ti Leggett wrote:
Tue Jul 2 10:39:04 2013 : Error: WARNING: Unresponsive child for request 0, in component <core> module <thread>
Fix your scripts so that they don't block the server.
The upstream server does get the request, send the reject back to the proxy and the proxy receives the reject but doesn't seem to send the reject back to the client. When the user types the password successfully everything works fine - the client gets an OK and none of the hung request errors show up.
The default configuration doesn't have this issue. Access-Requests can be proxied. Access-Rejects can be returned through a proxy to a client.
A debug log of one of these failed sessions is at http://pastebin.com/8n7snaBV. Any ideas what might be going on?
The debug log shows nothing interesting. The most probable issue is that your scripts are blocking the server. Fix that. You can verify this by configuring a test system *without* your scripts. Or a test user, which bypasses the scripts. It will work. Alan DeKok.
I'm not sure how the script could be blocking the server after it's already ran and returned the updated packet so the proxying can take place which does happen: • rlm_perl: Changing User-Name: leggett@yubiauth.mcs.example.com • rlm_perl: Added pair NAS-Port-Type = Virtual • rlm_perl: Added pair Service-Type = Authenticate-Only • rlm_perl: Added pair Auth-Type = System • rlm_perl: Added pair Calling-Station-Id = client.mcs.example.com • rlm_perl: Added pair User-Name = leggett@yubiauth.mcs.example.com • rlm_perl: Added pair User-Password = 654321 • rlm_perl: Added pair NAS-Identifier = sshd • rlm_perl: Added pair Stripped-User-Name = leggett • rlm_perl: Added pair NAS-IP-Address = 192.168.6.203 • rlm_perl: Added pair NAS-Port = 32448 • rlm_perl: Added pair Ldap-UserDn = uid=leggett,ou=people,dc=mcs,dc=example,dc=com • Cached username is "leggett@yubiauth.mcs.example.com", list username is "leggett@yubiauth.mcs.example.com" • ++[get_domain] returns updated • [suffix] Looking up realm "yubiauth.mcs.example.com" for User-Name = "leggett@yubiauth.mcs.example.com" • [suffix] Found realm "yubiauth.mcs.example.com" • [suffix] Adding Stripped-User-Name = "leggett" • [suffix] Adding Realm = "yubiauth.mcs.example.com" • [suffix] Proxying request from user leggett to realm yubiauth.mcs.example.com • [suffix] Preparing to proxy authentication request to realm "yubiauth.mcs.example.com" • Cached username is "leggett", list username is "leggett@yubiauth.mcs.example.com" • ++[suffix] returns updated The request packet then gets proxied off, comes back and this script is never called again. The same script gets called the same way on successful requests and this script is only called in the authorize phase. I've also tested that when one of the failure cases is reached (return RLM_MODULE_FAIL) that a fail packet is sent back to the client and no proxying ever takes place which is what I would expect. The script is at http://pastebin.com/gB91jj8W. On Jul 2, 2013, at 12:20 PM, Alan DeKok <aland@deployingradius.com> wrote:
Ti Leggett wrote:
Tue Jul 2 10:39:04 2013 : Error: WARNING: Unresponsive child for request 0, in component <core> module <thread>
Fix your scripts so that they don't block the server.
The upstream server does get the request, send the reject back to the proxy and the proxy receives the reject but doesn't seem to send the reject back to the client. When the user types the password successfully everything works fine - the client gets an OK and none of the hung request errors show up.
The default configuration doesn't have this issue. Access-Requests can be proxied. Access-Rejects can be returned through a proxy to a client.
A debug log of one of these failed sessions is at http://pastebin.com/8n7snaBV. Any ideas what might be going on?
The debug log shows nothing interesting.
The most probable issue is that your scripts are blocking the server. Fix that.
You can verify this by configuring a test system *without* your scripts. Or a test user, which bypasses the scripts. It will work.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Ti Leggett wrote:
I'm not sure how the script could be blocking the server after it's already ran and returned the updated packet so the proxying can take place which does happen:
I don't know. All I know is that the default configuration doesn't have child threads blocking when sending Access-Reject. The problem is due to a local change on your system. Alan DeKok.
On 2 Jul 2013, at 18:51, Alan DeKok <aland@deployingradius.com> wrote:
Ti Leggett wrote:
I'm not sure how the script could be blocking the server after it's already ran and returned the updated packet so the proxying can take place which does happen:
I don't know. All I know is that the default configuration doesn't have child threads blocking when sending Access-Reject.
The problem is due to a local change on your system.
There was a bug in rlm_perl which caused it to go into an infinite loop processing reply attributes. Check if radiusd is using 100% cpu, if it is, upgrade. Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team
I'm not seeing a spin lock, but I'm running a 2.2.1 branch version that I believe you pointed me at to fix an rlm_krb5 issue I was seeing earlier this year. Is there an update for that branch or should I be moving to some other version/branch? On Jul 2, 2013, at 1:03 PM, Arran Cudbard-Bell <a.cudbardb@freeradius.org> wrote:
On 2 Jul 2013, at 18:51, Alan DeKok <aland@deployingradius.com> wrote:
Ti Leggett wrote:
I'm not sure how the script could be blocking the server after it's already ran and returned the updated packet so the proxying can take place which does happen:
I don't know. All I know is that the default configuration doesn't have child threads blocking when sending Access-Reject.
The problem is due to a local change on your system.
There was a bug in rlm_perl which caused it to go into an infinite loop processing reply attributes. Check if radiusd is using 100% cpu, if it is, upgrade.
Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On 2 Jul 2013, at 19:28, Ti Leggett <leggett@mcs.anl.gov> wrote:
I'm not seeing a spin lock, but I'm running a 2.2.1 branch version that I believe you pointed me at to fix an rlm_krb5 issue I was seeing earlier this year. Is there an update for that branch or should I be moving to some other version/branch?
On Jul 2, 2013, at 1:03 PM, Arran Cudbard-Bell <a.cudbardb@freeradius.org> wrote:
On 2 Jul 2013, at 18:51, Alan DeKok <aland@deployingradius.com> wrote:
Ti Leggett wrote:
I'm not sure how the script could be blocking the server after it's already ran and returned the updated packet so the proxying can take place which does happen:
I don't know. All I know is that the default configuration doesn't have child threads blocking when sending Access-Reject.
The problem is due to a local change on your system.
There was a bug in rlm_perl which caused it to go into an infinite loop processing reply attributes. Check if radiusd is using 100% cpu, if it is, upgrade.
Then it's not the same issue. Break out GDB, set relevant breakpoints, and see where it's hanging, that's all I can suggest. Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team
Ok. I'll be firing up gdb and adding more logging. Before I did that I added a post_proxy detail log to see what the proxy server saw in that phase and for Access-Rejected packets they never get to the post_proxy section. Not sure if that sheds any more light on this. Anyway, so I know where to focus my debugging, I want to make sure I understand how a proxied packet makes its way through the system. Is the path: authorize -> pre_proxy -> post_proxy That's how it looks from the debug logs. Do the authenticate sections ever get hit? Any other sections I should look into? On Jul 2, 2013, at 3:33 PM, Arran Cudbard-Bell <a.cudbardb@freeradius.org> wrote:
On 2 Jul 2013, at 19:28, Ti Leggett <leggett@mcs.anl.gov> wrote:
I'm not seeing a spin lock, but I'm running a 2.2.1 branch version that I believe you pointed me at to fix an rlm_krb5 issue I was seeing earlier this year. Is there an update for that branch or should I be moving to some other version/branch?
On Jul 2, 2013, at 1:03 PM, Arran Cudbard-Bell <a.cudbardb@freeradius.org> wrote:
On 2 Jul 2013, at 18:51, Alan DeKok <aland@deployingradius.com> wrote:
Ti Leggett wrote:
I'm not sure how the script could be blocking the server after it's already ran and returned the updated packet so the proxying can take place which does happen:
I don't know. All I know is that the default configuration doesn't have child threads blocking when sending Access-Reject.
The problem is due to a local change on your system.
There was a bug in rlm_perl which caused it to go into an infinite loop processing reply attributes. Check if radiusd is using 100% cpu, if it is, upgrade.
Then it's not the same issue.
Break out GDB, set relevant breakpoints, and see where it's hanging, that's all I can suggest.
Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On 3 Jul 2013, at 17:19, Ti Leggett <leggett@mcs.anl.gov> wrote:
Ok. I'll be firing up gdb and adding more logging. Before I did that I added a post_proxy detail log to see what the proxy server saw in that phase and for Access-Rejected packets they never get to the post_proxy section. Not sure if that sheds any more light on this.
Anyway, so I know where to focus my debugging, I want to make sure I understand how a proxied packet makes its way through the system. Is the path:
authorize -> pre_proxy -> post_proxy
That's how it looks from the debug logs. Do the authenticate sections ever get hit?
That's the correct flow. authorize -> pre-proxy -> post-proxy -> post-auth Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team
Ti Leggett wrote:
Ok. I'll be firing up gdb and adding more logging. Before I did that I added a post_proxy detail log to see what the proxy server saw in that phase and for Access-Rejected packets they never get to the post_proxy section.
I'm not sure how that happens. The proxy reply is *immediately* processed through the post_proxy section.
Not sure if that sheds any more light on this.
Anyway, so I know where to focus my debugging, I want to make sure I understand how a proxied packet makes its way through the system. Is the path:
authorize -> pre_proxy -> post_proxy
That's how it looks from the debug logs. Do the authenticate sections ever get hit? Any other sections I should look into?
No. See src/main/event.c. It's complicated, but there aren't many references to processing the proxy reply. Alan DeKok.
Well sure. I figured it was in my local configuration, but is there any other debugging I can do to help me pinpoint what may be going on since, as you said, from the debug logs everything looks correct? Disabling the script will give me a working installation but not a usable one in our environment. The default configuration will do the same. Is there anyway to get more specifics about what exactly is hanging? It might not be the script hanging directly (obviously since it's not hanging before the proxy or after a successful proxy) but could be another module hanging because of how the script modifies the packet. On Jul 2, 2013, at 12:51 PM, Alan DeKok <aland@deployingradius.com> wrote:
Ti Leggett wrote:
I'm not sure how the script could be blocking the server after it's already ran and returned the updated packet so the proxying can take place which does happen:
I don't know. All I know is that the default configuration doesn't have child threads blocking when sending Access-Reject.
The problem is due to a local change on your system.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Ti Leggett wrote:
Well sure. I figured it was in my local configuration, but is there any other debugging I can do to help me pinpoint what may be going on since, as you said, from the debug logs everything looks correct? Disabling the script will give me a working installation but not a usable one in our environment. The default configuration will do the same.
Not really. Maybe upgrading will work.
Is there anyway to get more specifics about what exactly is hanging?
See doc/bugs Debugging it will require C skills.
It might not be the script hanging directly (obviously since it's not hanging before the proxy or after a successful proxy) but could be another module hanging because of how the script modifies the packet.
Maybe. Alan DeKok.
participants (3)
-
Alan DeKok -
Arran Cudbard-Bell -
Ti Leggett