RE: ssh_channel_request_exec is Failing, returning -1.

["V Sidnal, Nagraju" <nagraju.sidnal@xxxxxxxxxxx>]

Hi Anderson,

Thanks for reply, But our issue is different. We have created client application using libssh .
Our issue is ssh_channel_request_exec is returning -1 when we are trying to execute command, using our libssh client .

ssh_channel_request_exec(channel, command.c_str());

In my first email I have explained my issue in detail. Could you please go through it.

Regards,
Nagraju

-----Original Message-----
From: Anderson Sasaki <ansasaki@xxxxxxxxxx> 
Sent: Friday, June 19, 2020 3:22 PM
To: libssh@xxxxxxxxxx
Subject: Re: ssh_channel_request_exec is Failing, returning -1.

Hello,

----- Original Message -----
> From: "V Sidnal, Nagraju" <nagraju.sidnal@xxxxxxxxxxx>
> To: libssh@xxxxxxxxxx
> Sent: Friday, June 19, 2020 11:22:24 AM
> Subject: ssh_channel_request_exec is Failing, returning -1.
> 
> Hello All,
> 
> We have written ssh client using lissh to connect to Device(Having SSH 
> Server
> )
> Our Sample application works with OpenSSH Server in Our Machine(Windows OS).
> *****************************************************
> However it is not working with Device. Below is sample code.
> ***************************************************
> 
> channel = ssh_channel_new(my_ssh_session); rc = 
> ssh_channel_open_session(channel);
> rc = ssh_channel_request_exec(channel, command.c_str());
> 
> so here ssh_channel_request_exe() is failing , it is returning -1.
> ****************************************************
> Below is application log.(detailed log attached:
> LibSSH_SampleApplication_failedwithDevice.txt)
> *****************************************************
> [2020/06/18 09:46:16.881442, 3] ssh_packet_userauth_success:  
> Authentication successful
> [2020/06/18 09:46:16.884442, 4] ssh_packet_userauth_success:  Received 
> SSH_USERAUTH_SUCCESS
> [2020/06/18 09:46:16.886442, 3] ssh_packet_need_rekey:  packet:
> [data_rekey_needed=0, out_blocks=13, in_blocks=11
> [2020/06/18 09:46:16.889442, 3] ssh_packet_need_rekey:  packet:
> [data_rekey_needed=0, out_blocks=13, in_blocks=11 
> ssh_userauth_publickey ssh_is_connected
> [2020/06/18 09:46:16.900442, 2] channel_open:  Creating a channel 43 
> with
> 64000 window and 32768 max packet
> [2020/06/18 09:46:16.903442, 3] ssh_packet_need_rekey:  packet:
> [data_rekey_needed=0, out_blocks=14, in_blocks=12
> [2020/06/18 09:46:16.907442, 3] ssh_socket_unbuffered_write:  Enabling 
> POLLOUT for socket
> [2020/06/18 09:46:16.914442, 3] packet_send2:  packet: wrote [type=90, 
> len=44, padding_size=19, comp=24, payload=24]
> [2020/06/18 09:46:16.917442, 3] channel_open:  Sent a 
> SSH_MSG_CHANNEL_OPEN type session for channel 43
> [2020/06/18 09:46:16.924442, 4] ssh_socket_pollcallback:  Poll 
> callback on socket 212 (POLLIN POLLOUT ), out buffer 0
> [2020/06/18 09:46:16.926442, 3] ssh_packet_socket_callback:  packet: 
> read type 91 [len=28,padding=10,comp=17,payload=17]
> [2020/06/18 09:46:16.930442, 3] ssh_packet_process:  Dispatching 
> handler for packet type 91
> [2020/06/18 09:46:16.933442, 3] ssh_packet_channel_open_conf:  
> Received SSH2_MSG_CHANNEL_OPEN_CONFIRMATION
> [2020/06/18 09:46:16.936442, 2] ssh_packet_channel_open_conf:  
> Received a CHANNEL_OPEN_CONFIRMATION for channel 43:0
> [2020/06/18 09:46:16.939442, 2] ssh_packet_channel_open_conf:  Remote 
> window
> : 0, maxpacket : 32768
> [2020/06/18 09:46:16.942442, 3] ssh_packet_need_rekey:  packet:
> [data_rekey_needed=0, out_blocks=14, in_blocks=12
> [2020/06/18 09:46:16.945442, 4] ssh_socket_pollcallback:  sending 
> control flow event
> [2020/06/18 09:46:16.953442, 4] ssh_packet_socket_controlflow_callback:
> sending channel_write_wontblock callback
> ssh_channel_open_session:: returned Code= 0 ssh_is_connected
> [2020/06/18 09:46:16.968442, 3] ssh_packet_need_rekey:  packet:
> [data_rekey_needed=0, out_blocks=16, in_blocks=14
> [2020/06/18 09:46:16.971442, 3] ssh_socket_unbuffered_write:  Enabling 
> POLLOUT for socket
> [2020/06/18 09:46:16.973442, 3] packet_send2:  packet: wrote [type=98, 
> len=44, padding_size=8, comp=35, payload=35]
> [2020/06/18 09:46:16.977442, 3] channel_request:  Sent a 
> SSH_MSG_CHANNEL_REQUEST exec
> [2020/06/18 09:46:16.980442, 4] ssh_socket_pollcallback:  Poll 
> callback on socket 212 (POLLIN POLLOUT ), out buffer 0
> [2020/06/18 09:46:16.984442, 3] ssh_packet_socket_callback:  packet: 
> read type 100 [len=12,padding=6,comp=5,payload=5]
> [2020/06/18 09:46:16.992442, 3] ssh_packet_process:  Dispatching 
> handler for packet type 100
> [2020/06/18 09:46:16.995442, 3] ssh_packet_channel_failure:  Received 
> SSH_CHANNEL_FAILURE on channel (43:0)
> [2020/06/18 09:46:16.999442, 3] ssh_packet_need_rekey:  packet:
> [data_rekey_needed=0, out_blocks=16, in_blocks=12
> [2020/06/18 09:46:17.004442, 4] ssh_socket_pollcallback:  sending 
> control flow event
> [2020/06/18 09:46:17.007442, 4] ssh_packet_socket_controlflow_callback:
> sending channel_write_wontblock callback
> [2020/06/18 09:46:17.010442, 1] channel_request:  Channel request exec 
> failed
> ssh_channel_request_exec:: returned Code= -1
> 
> **********************************************************************
> ***********************************
> Then we check with Openssh Client to Device (session parameter & 
> command together : ssh hostname privatekey command) It failed , below 
> is the log (detailed log attached:
> OpenSSH_Client__ConnectionParamterAndCommandTogether_Fails.txt)
> 
> debug1: Authentication succeeded (publickey).
> Authenticated to xxx.xx.x.xx ([xxx.xx.x.xx]:22).
> debug1: channel 0: new [client-session]
> debug3: ssh_session2_open: channel_new: 0
> debug2: channel 0: send open
> debug3: send packet: type 90
> debug1: Requesting no-more-sessions@xxxxxxxxxxx
> debug3: send packet: type 80
> debug1: Entering interactive session.
> debug1: pledge: network
> debug3: receive packet: type 91
> debug2: channel_input_open_confirmation: channel 0: callback start
> debug2: fd 3 setting TCP_NODELAY
> debug3: ssh_packet_set_tos: set IP_TOS 0x08
> debug2: client_session2_setup: id 0
> debug1: Sending command: StartDevice
> debug2: channel 0: request exec confirm 1
> debug3: send packet: type 98
> debug2: channel_input_open_confirmation: channel 0: callback done
> debug2: channel 0: open confirm rwindow 0 rmax 32768
> debug3: receive packet: type 100
> debug2: channel_input_status_confirm: type 100 id 0 exec request 
> failed on channel 0
> **********************************************************************
> *******************************************
> Then we check with Openssh Client to device (First SESSION ESTABLISHED 
> & THEN COMMAND EXECUTION) :: Success Scenario After creating session 
> we can execute the command its connecting and below is debug log of 
> openssh(detailed log is attached :
> OpenSSh_Client_FirstSession_then_cmd_exe_Success_reqpty.txt)
> 
> debug1: Authentication succeeded (publickey).
> Authenticated to XXX.XXX.X.XX ([XXX.XXX.X.XX]:22).
> debug1: channel 0: new [client-session]
> debug3: ssh_session2_open: channel_new: 0
> debug2: channel 0: send open
> debug3: send packet: type 90
> debug1: Requesting no-more-sessions@xxxxxxxxxxx
> debug3: send packet: type 80
> debug1: Entering interactive session.
> debug1: pledge: network
> debug3: receive packet: type 91
> debug2: channel_input_open_confirmation: channel 0: callback start
> debug2: fd 3 setting TCP_NODELAY
> debug3: ssh_packet_set_tos: set IP_TOS 0x10
> debug2: client_session2_setup: id 0
> debug2: channel 0: request pty-req confirm 1
> debug3: send packet: type 98
> debug2: channel 0: request shell confirm 1
> debug3: send packet: type 98
> debug2: channel_input_open_confirmation: channel 0: callback done
> debug2: channel 0: open confirm rwindow 0 rmax 32768
> debug3: receive packet: type 99
> debug2: channel_input_status_confirm: type 99 id 0
> debug2: PTY allocation request accepted on channel 0
> debug2: channel 0: rcvd adjust 2097152
> debug3: receive packet: type 99
> debug2: channel_input_status_confirm: type 99 id 0
> debug2: shell request accepted on channel 0
> 
> **********************************************************************
> ***************************************
> In ABOVE log we found that it is making pty req. so we thought 
> ssh_channel_request_pty is requiured we did below code
> 
> channel = ssh_channel_new(my_ssh_session); rc = 
> ssh_channel_open_session(channel);
> rc = ssh_channel_request_pty(channel); rc = 
> ssh_channel_request_shell(channel);
> rc = ssh_channel_request_exec(channel, command.c_str());
> 
> However it is still failing , Please find below log (detailed log attached :
> LibSSH_SampleApplication_failedwithdevicewith_PTY.txt)
> [2020/06/18 12:36:55.038442, 2] channel_open:  Creating a channel 43 
> with
> 64000 window and 32768 max packet
> [2020/06/18 12:36:55.044442, 2] ssh_packet_channel_open_conf:  
> Received a CHANNEL_OPEN_CONFIRMATION for channel 43:0
> [2020/06/18 12:36:55.046442, 2] ssh_packet_channel_open_conf:  Remote 
> window
> : 0, maxpacket : 32768
> ssh_channel_open_session:: returned Code= 0
> [2020/06/18 12:36:55.061442, 2] channel_request:  Channel request 
> pty-req success
> [2020/06/18 12:36:55.159442, 2] channel_rcv_change_window:  Adding 
> 2097152 bytes to channel (43:0) (from 0 bytes)
> [2020/06/18 12:36:55.161442, 2] channel_request:  Channel request 
> shell success ssh_is_connected
> [2020/06/18 12:36:55.176442, 2] grow_window:  growing window (channel 
> 43:0) to 1280000 bytes
> [2020/06/18 12:36:55.182442, 1] channel_request:  Channel request exec 
> failed
> ssh_channel_request_exec:: returned Code= -1
> 
> Please provide your valuable suggestion/inputs to address the 
> described problem.

Thank you for reporting, there is a fix I proposed in https://eur01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgitlab.com%2Flibssh%2Flibssh-mirror%2F-%2Fmerge_requests%2F122&amp;data=02%7C01%7Cnagraju.sidnal%40siemens.com%7C2e133585ad6e4b4c699e08d814368206%7C38ae3bcd95794fd4addab42e1495d55a%7C1%7C0%7C637281571624023822&amp;sdata=NL%2FcH249v8bt1rduBLspdb%2BOQKoQoRS32trZ4hVF284%3D&amp;reserved=0

Could you please check if it fixes the issue for you?

Thank you,
Anderson