"ERR sshd: error: no more sessions" issue

[Praseed V Gopal]

Hi Damien,
Thanks for your reply.
One more question.
Doesn't the channel ever time-out after sending the close?
Or is it always required the channel to receive close from remote?

BTW, I discussed with the Java person, he is using Ganymed-SSH2 Java library
(now bounty castle).
Is there any known  interoperability  issues  here?

Thanks & Regards
Praseed

On Fri, May 30, 2008 at 12:39 PM, Damien Miller <djm at mindrot.org> wrote:

> On Fri, 30 May 2008, Praseed V Gopal wrote:
>
> > Initially send this mail to user group. then realized this is more apt
> > place. Apologies for posting in both groups...
> >
> > Hi all,
> > We're using openssh version 4.7p on our linux 2.6-22 kernel.
> > We have a Java based GUI that opens a secure shell connection to this
> linux box.
> > To do something over the connection, the GUI opens a session (some
> > times 3-4 simultaneous sessions) & once done, it will close the
> > connection gracefully (I believe).
> > The problem is after a few sessions (10) are open & closed, we see
> > "May 29 14:43:11 ERR sshd[534]: error: no more sessions" error.
> > So I checked the source code of openssh & changed the value of
> > MAX_SESSIONS  from 10 to 100.in session.c @ line number 132.
> >
> > Things got improved, but now after number of sessions crosses 100, the
> > same error pops up.
> > I enabled the debug mode. Debug messages are at the end of this mail.
> >
> > 1) Please tell me, whether the sessions are getting closed properly?
> >  2) If yes, why it is not decrementing the used sessions & reusing the
> > already closed sessions?
> > 3) is this supposed to work this way?
> > 4) How do I fix it or work around this?
>
> It looks like the problem lies with your Java client. Compare the sequence
> of a successful session closure:
>
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: read<=0 rfd 105 len
> 0
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: read failed
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: close_read
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: input open -> drain
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: ibuf_empty
> > delayed efd 107/(0)
> > May 29 14:43:10 DEBUG sshd[534]: debug2: notify_done: reading
> > May 29 14:43:10 DEBUG sshd[534]: debug1: Received SIGCHLD.
> > May 29 14:43:10 DEBUG sshd[534]: debug1: session_by_pid: pid 2518
> > May 29 14:43:10 DEBUG sshd[534]: debug1: session_exit_message: session
> > 98 channel 98 pid 2518
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: request
> > exit-status confirm 0
> > May 29 14:43:10 DEBUG sshd[534]: debug1: session_exit_message: release
> > channel 98
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: write failed
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: close_write
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: output open ->
> closed
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: read 0 from efd 107
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: closing read-efd 107
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: ibuf empty
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: send eof
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: input drain ->
> closed
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: send close
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: rcvd close
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: is dead
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: gc: notify user
> > May 29 14:43:10 DEBUG sshd[534]: debug1: session_by_channel: session
> > 98 channel 98
> > May 29 14:43:10 DEBUG sshd[534]: debug1: session_close_by_channel:
> > channel 98 child 0
> > May 29 14:43:10 DEBUG sshd[534]: debug1: session_close: session 98 pid 0
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: gc: user detached
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: is dead
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: garbage collecting
> > May 29 14:43:10 DEBUG sshd[534]: debug1: channel 98: free:
> > server-session, nchannels 99
>
> Broadly speaking, a "channel" is the SSH protocol's abstraction for a
> bidirectional pipe, and a "session" handles command/shell/subsystem
> execution. A session uses a channel for communication.
>
> The sequence here is:
>
> 1. channel read failed
> 2. child process exited
> 3. simulate a channel write failure (the child process is gone by now)
> 4. send channel eof
> 5. wait for input to drain (in this case it already has)
> 6. send channel close
> 7. *remote* sends a channel close
> 8. session is detached from channel
> 9. channel is freed
>
> Here is one that failed to clean up properly.
>
> > May 29 14:43:10 DEBUG sshd[534]: debug2: fd 107 setting O_NONBLOCK
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: read<=0 rfd 105 len
> 0
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: read failed
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: close_read
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: input open -> drain
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: ibuf_empty
> > delayed efd 107/(0)
> > May 29 14:43:10 DEBUG sshd[534]: debug2: notify_done: reading
> > May 29 14:43:10 DEBUG sshd[534]: debug1: Received SIGCHLD.
> > May 29 14:43:10 DEBUG sshd[534]: debug1: session_by_pid: pid 2519
> > May 29 14:43:10 DEBUG sshd[534]: debug1: session_exit_message: session
> > 98 channel 98 pid 2519
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: request
> > exit-status confirm 0
> > May 29 14:43:10 DEBUG sshd[534]: debug1: session_exit_message: release
> > channel 98
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: write failed
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: close_write
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: output open ->
> closed
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: read 0 from efd 107
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: closing read-efd 107
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: ibuf empty
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: send eof
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: input drain ->
> closed
> > May 29 14:43:10 DEBUG sshd[534]: debug2: channel 98: send close
>
> Here steps 1-6 happened, but the remote end never replied with a channel
> close. This means the server cannot continue to detach the session from
> the channel and deallocate the channel.
>
> Increasing MAX_SESSIONS will only forestall the inevitable: your client
> is not closing channels properly, which causes a session leak on the
> server.
>
> -d
>