[erlang-bugs] ssh bug: bad window_adjust response

[Ingela Anderton Andin]

Hello!

Yes that is a bug, thanks for catching it. I will fix it.

Regards Ingela Erlang OTP/team - Ericsson AB

Daniel Goertzen wrote:
> 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.
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> erlang-bugs mailing list
> erlang-bugs@REDACTED
> http://erlang.org/mailman/listinfo/erlang-bugs
>