[erlang-bugs] ssh bug: bad window_adjust response

[Daniel Goertzen]

Okay, I've found the real bug now. :)

When Erlang ssh receives a "ssh_msg_channel_window_adjust" message and
there is outstanding data to transmit, the code will generate
"ssh_msg_channel_data" messages with the wrong channel number.  The remote
system observes a protocol error and drops the connection.

The problem is in ssh_connection.erl approximately line 450:

handle_msg(#ssh_msg_channel_window_adjust{recipient_channel = *ChannelId*,
  bytes_to_add = Add},
   #connection{channel_cache = Cache} = Connection,
   ConnectionPid, _) ->

    #channel{send_window_size = Size} =
Channel0 = ssh_channel:cache_lookup(Cache, ChannelId),

    {SendList, Channel} =  %% TODO: Datatype 0 ?
update_send_window(Channel0#channel{send_window_size = Size + Add},
   0, <<>>, Connection),

    Replies = lists:map(fun({Type, Data}) ->
{connection_reply, ConnectionPid,
 channel_data_msg(*ChannelId*, Type, Data)}  % <-- *bzzt, wrong*
end, SendList),
    FlowCtrlMsgs = flow_control(Channel, Cache),
    {{replies, Replies ++ FlowCtrlMsgs}, Connection};


Below is a trace of a channel where I did a ssh_connection:send() of a 13MB
binary.  The first window worth of data is correctly sent to channel 2, but
the second window of data is incorrectly sent to channel 7.  The remote SSH
is OpenSSH.  See bolded sections below

firmware size 13417472
c{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{ssh_msg_channel_open,"session",7,65536,32768,<<0
bytes>>}}]}
al{<0.134.0>,"->",ssh_connection,handle_msg,[{ssh_msg_channel_open_confirmation,7,2,0,32768,<<0
bytes>>},{connection,[{7,{<0.145.0>,#Ref<0.0.0.630>}}],65583,[],8,undefined,undefined,undefined,undefined,undefined,undefined,<0.133.0>},<0.135.0>,client]}
ling exec now...
opening channel
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{channel_requst_reply,{<0.145.0>,#Ref<0.0.0.630>},{open,7}}]}
calling ssh exec
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{ssh_msg_channel_request,2,"exec",true,[<<16
bytes>>]}}]}
{<0.134.0>,"->",ssh_connection,handle_msg,[{ssh_msg_channel_window_adjust,7,87380},{connection,[{7,{<0.145.0>,#Ref<0.0.0.634>}}],65583,[],8,undefined,undefined,undefined,undefined,undefined,undefined,<0.133.0>},<0.135.0>,client]}
{<0.134.0>,"->",ssh_connection,handle_msg,[{ssh_msg_channel_success,7},{connection,[{7,{<0.145.0>,#Ref<0.0.0.634>}}],65583,[],8,undefined,undefined,undefined,undefined,undefined,undefined,<0.133.0>},<0.135.0>,client]}
ca{<0.134.0>,"->",ssh_connection_manager,send_msg,[{channel_requst_reply,{<0.145.0>,#Ref<0.0.0.634>},success}]}
lled send_stdin
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{
*ssh_msg_channel_data,2*,<<32768 bytes>>}}]}
in{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{
*ssh_msg_channel_data,2*,<<32768 bytes>>}}]}
 {<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{
*ssh_msg_channel_data,2*,<<21844 bytes>>}}]}
i{<0.134.0>,"->",ssh_connection_manager,send_msg,[{flow_control,65583,{channel,"session","exec",<0.145.0>,{<0.145.0>,#Ref<0.0.0.639>},7,65536,32768,false,2,0,32768,false,[{0,<<13330092
bytes>>}]},{<0.145.0>,#Ref<0.0.0.639>},ok}]}
o loop
{<0.134.0>,"->",ssh_connection,handle_msg,[{*ssh_msg_channel_window_adjust*,
*7*
,124222},{connection,[],65583,[],8,undefined,undefined,undefined,undefined,undefined,undefined,<0.133.0>},<0.135.0>,client]}
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{
*ssh_msg_channel_data,7*,<<32768 bytes>>}}]}
io{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{
*ssh_msg_channel_data,7*,<<32768 bytes>>}}]}
 loop got{data,7,1,<<"calling_user 101\nfile_user 0\n">>}
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{
*ssh_msg_channel_data,7*,<<32768 bytes>>}}]}
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{
*ssh_msg_channel_data,7*,<<25918 bytes>>}}]}
i{<0.134.0>,"->",ssh_connection,handle_msg,[{ssh_msg_channel_extended_data,7,1,<<29
bytes>>},{connection,[],65583,[],8,undefined,undefined,undefined,undefined,undefined,undefined,<0.133.0>},<0.135.0>,client]}
n
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{channel_data,<0.145.0>,{data,7,1,<<29
bytes>>}}]}
io loop
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{ssh_msg_channel_window_adjust,2,29}}]}
{<0.134.0>,"->",ssh_connection,handle_msg,[{ssh_msg_channel_extended_data,7,1,<<25
bytes>>},{connection,[],65583,[],8,undefined,undefined,undefined,undefined,undefined,undefined,<0.133.0>},<0.135.0>,client]}
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{channel_data,<0.145.0>,{data,7,1,<<25
bytes>>}}]}
io loop got{data,7,1,<<"proceeding with transfer\n">>}
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{connection_reply,<0.135.0>,{ssh_msg_channel_window_adjust,2,25}}]}
in io loop
{<0.134.0>,"->",ssh_connection,handle_msg,[*{ssh_msg_disconnect,2,"Received
data for nonexistent channel 7*
.",[]},{connection,[],65583,[],8,undefined,undefined,undefined,undefined,undefined,undefined,<0.133.0>},<0.135.0>,client]}
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{channel_data,<0.145.0>,{closed,7}}]}
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{channel_data,<0.132.0>,{closed,6}}]}
{<0.134.0>,"->",ssh_connection_manager,send_msg,[{channel_data,<0.132.0>,{closed,5}}]}


Dan.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://erlang.org/pipermail/erlang-bugs/attachments/20120827/a39f903b/attachment.htm>