proxy server goes deaf after "Client has closed connection" (RadSec to home server)

[Brian Julin]

It appears there was another layer to my latest issue.

Sometimes a server using RadSec to proxy to a home server ends up
just waiting around unable to see any more incoming requests,
and not having completed the current request.

In this case the server is 3.0, and is sandwiched
between our internal instance and our federation server (doing
radsecproxy-ish stuff.)

This may only happen in a corner case when the federation server is
taking a while to reply, perhaps in this case where it exceeds our
internal instance's response_window.

I'm testing now whether using an immense response_window on
the internal instance works as a workaround (assuming the
federation server doesn't have any prolonged issues, of course)
which would help support that theory.

Info: (32) Proxying request to home server XXX.XXX.XXX.XXX port 2083
Tue Mar  6 13:59:08 2012 : Debug: Proxy is writing 122 bytes to SSL
Tue Mar  6 13:59:08 2012 : Debug: Thread 3 waiting to be assigned a request
Tue Mar  6 13:59:08 2012 : Debug: Proxy SSL socket has data to read
Tue Mar  6 13:59:08 2012 : Debug: Client has closed connection

(though, the client is UDP which has no transport layer connection, so...
 maybe that's talking about the home server, not a client?  Not sure if that's
 coming from listen.c or tls_listen.c)

(at this point the server does not see any additional requests sent to it,
 so we kill it to see if it is hanging out anywhere interesting... really should
 do this several times more to verify... maybe try a kill -9 next time...)

Program received signal SIGINT, Interrupt.
0x0000003c7520dff4 in __lll_lock_wait () from /lib64/libpthread.so.0

#0  0x0000003c7520dff4 in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x0000003c75209328 in _L_lock_854 () from /lib64/libpthread.so.0
#2  0x0000003c752091f7 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x000000000042bb54 in remove_from_proxy_hash (request=0x805170)
    at process.c:1579
#4  0x000000000042d4f5 in request_done (request=<value optimized out>, 
    action=<value optimized out>) at process.c:532
#5  0x000000000042f42d in remove_all_proxied_requests (
    ctx=<value optimized out>, data=<value optimized out>) at process.c:1540
#6  0x00007ffff7de7822 in WalkNodeInOrder (X=<value optimized out>, 
    callback=0x42f400 <remove_all_proxied_requests>, context=0x7fffec003710)
    at rbtree.c:551
#7  0x0000000000431354 in event_new_fd (this=0x7fffec003710) at process.c:3553
#8  0x000000000043c648 in proxy_tls_recv (listener=0x7fffec003710)
    at tls_listen.c:499
#9  0x0000000000430a8a in event_socket_handler (xel=<value optimized out>, 
    fd=<value optimized out>, ctx=0x7fffec003710) at process.c:3309
#10 0x00007ffff7deddfb in fr_event_loop (el=0x7d0b10) at event.c:415
#11 0x0000000000422534 in main (argc=<value optimized out>, 
    argv=<value optimized out>) at radiusd.c:413



Just one of those occasions where  the grass looks greener on the SEGV
side of the fence :-)