0 votes
by (120 points)

I am encountering an issue where I get an error “ssh2.exceptions.ChannelRequestDenied” while trying to send commands to Rebex Server after successfully establishing ssh connection, Server log shows “Connection reset by peer”.

Create New Binary Protocol Class
Binary Protocol Max Transmit Size: 4000
Session 63: Started on connection from 10.0.1.129:32956.
Session 63: Authentication for 'B' succeeded.
Session 63: Connection reset by peer.
Session 63: Closed connection from 10.0.1.129:32956.

FYI, I am able to run same python script on linux server to do ssh and run commands...

client = ParallelSSHClient(hosts, hostconfig=hostconfig)

output = client.runcommand('%s %s', hostargs=(('pwd', 'ls',),
('pwd', 'pwd',),))

Thanks in advance!

1 Answer

0 votes
by (72.7k points)
edited by

UPDATE:

The log showed that the ParallelSSHClient requested auth-agent-req@openssh.com extension, which is not supported.

Solution is to disable this feature on client, so the extension will not be requested.


Can you please create communication log in Verbose level and post it here or send it to support@rebex.net for analysis. It can be created like this:

var server = new FileServer();
server.LogWriter = new Rebex.FileLogWriter("C:/data/ssh.log", Rebex.LogLevel.Verbose);
by (120 points)
Here is what I see in log:

2018-10-01 10:37:27.079 DEBUG FileServer(1)[74] Server: Accepted connection from 10.0.1.129:35942.
2018-10-01 10:37:27.079 INFO FileServer(1)[74] Server: Session 10: Started on connection from 10.0.1.129:35942.
2018-10-01 10:37:27.079 DEBUG FileServer(1)[74] SSH: Session 10: Local SSH version: SSH-2.0-RebexSSH_1.0.6391.0
2018-10-01 10:37:27.079 DEBUG FileServer(1)[74] SSH: Session 10: Remote SSH version: SSH-2.0-libssh2_1.8.1_DEV
2018-10-01 10:37:27.079 DEBUG FileServer(1)[74] SSH: Session 10: Performing algorithm negotiation and key exchange.
2018-10-01 10:37:27.079 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_KEXINIT (768 bytes).
2018-10-01 10:37:27.079 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_KEXINIT (880 bytes).
2018-10-01 10:37:27.079 DEBUG FileServer(1)[74] SSH: Session 10: Performing key exchange using diffie-hellman-group-exchange-sha256 with ssh-rsa.
2018-10-01 10:37:27.282 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_PACKET34 (24 bytes).
2018-10-01 10:37:27.282 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_KEXDH_REPLY (408 bytes).
2018-10-01 10:37:27.297 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_PACKET32 (208 bytes).
2018-10-01 10:37:27.329 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_PACKET33 (768 bytes).
2018-10-01 10:37:27.329 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_NEWKEYS (16 bytes).
2018-10-01 10:37:27.329 DEBUG FileServer(1)[74] SSH: Session 10: Current encryptor is aes128-ctr/hmac-sha2-256.
2018-10-01 10:37:27.344 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_NEWKEYS (16 bytes).
2018-10-01 10:37:27.344 DEBUG FileServer(1)[74] SSH: Session 10: Current decryptor is aes128-ctr/hmac-sha2-256.
2018-10-01 10:37:27.344 DEBUG FileServer(1)[74] SSH: Session 10: Key exchange finished.
2018-10-01 10:37:27.563 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_SERVICE_REQUEST (64 bytes).
2018-10-01 10:37:27.563 DEBUG FileServer(1)[74] SSH: Session 10: Performing authentication.
2018-10-01 10:37:27.563 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_SERVICE_ACCEPT (64 bytes).
2018-10-01 10:37:27.563 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_USERAUTH_REQUEST (96 bytes).
2018-10-01 10:37:27.563 DEBUG FileServer(1)[74] SSH: Session 10: Starting authentication as 'B' for 'ssh-connection'.
2018-10-01 10:37:27.688 INFO FileServer(1)[74] Server: Session 10: Authentication for 'B' succeeded.
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_USERAUTH_SUCCESS (48 bytes).
2018-10-01 10:37:27.688 DEBUG FileServer(1)[74] SSH: Session 10: Authenticated as 'B' for 'ssh-connection'.
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_CHANNEL_OPEN (80 bytes).
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_CHANNEL_OPEN_CONFIRMATION (64 bytes).
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_CHANNEL_REQUEST (80 bytes).
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_CHANNEL_FAILURE (48 bytes).
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_CHANNEL_REQUEST (80 bytes).
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_CHANNEL_FAILURE (48 bytes).
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_CHANNEL_EOF (48 bytes).
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Sent packet SSH_MSG_CHANNEL_CLOSE (48 bytes).
2018-10-01 10:37:27.688 VERBOSE FileServer(1)[74] SSH: Session 10: Received packet SSH_MSG_CHANNEL_CLOSE (48 bytes).
2018-10-01 10:37:27.719 INFO FileServer(1)[74] SSH: Session 10: Connection reset by peer.
2018-10-01 10:37:27.719 INFO FileServer(1)[74] Server: Session 10: Closed connection from 10.0.1.129:35942.
by (72.7k points)
Does this occur with the latest version as well?
  It seems that your support contract has expired. You can
download the latest trial version from https://www.rebex.net/file-server/download.aspx

Did you enable Shell subsystem by calling:
  server.Bind(22, FileServerProtocol.Shell)
by (120 points)
Yes Shell subsystem is enables. I am still not sure what Rebex does not like about Parallel SSH (PSSH) and a disconnection is sent.

In the mean time, I also tried Subprocess to pass multiple commands as below:

from subprocess import call

connect = 'connect'+box_ip+' '
search = 'search time_out'+' '
disconnect = 'disconnect'

args = "ssh " + 'B@10.0.0.20 -p 2107 '\
                         + 'help '           \
             + connect \
             + search \
             + disconnect,

s=call(args, shell=True)

In above script execution during debugging we found that Rebex receives only first command help and rest of the commands as arguments!
How can we differentiate between  command and arguments? Some commands will have no arguments and some will have many.
by (72.7k points)
It seems that PSSH requested unsupported channel. Can you please use log level 0:

    server.LogWriter = new Rebex.FileLogWriter("C:/data/ssh.log", (Rebex.LogLevel)0);

And post here part of the log from the point the SSH_MSG_CHANNEL_OPEN was received. In level 0 the log will contain also raw data received from the client. So we will be able to see, what the client actually requested.

The produced log can look like this:

2018-10-05 17:27:32.700 VERBOSE FileServer(1)[7] SSH: Session 1: Received packet SSH_MSG_CHANNEL_OPEN (80 bytes).
2018-10-05 17:27:32.701 LEVEL0 FileServer(1)[7] SSH: Received packet data:
 0000 |5A-00-00-00-07-73-65-73 73-69-6F-6E-00-00-00-00| Z....session....
 0010 |00-00-80-00-00-00-78-00                        | ......x.
2018-10-05 17:27:32.716 VERBOSE FileServer(1)[7] SSH: Session 1: Sent packet SSH_MSG_CHANNEL_OPEN_CONFIRMATION (64 bytes).
2018-10-05 17:27:32.721 VERBOSE FileServer(1)[7] SSH: Session 1: Received packet SSH_MSG_CHANNEL_REQUEST (96 bytes).
2018-10-05 17:27:32.722 LEVEL0 FileServer(1)[7] SSH: Received packet data:
 0000 |62-00-00-00-00-00-00-00 07-70-74-79-2D-72-65-71| b........pty-req
 0010 |01-00-00-00-05-78-74-65 72-6D-00-00-00-50-00-00| .....xterm...P..
 0020 |00-19-00-00-02-80-00-00 01-90-00-00-00-00      | ..............
2018-10-05 17:27:32.735 VERBOSE FileServer(1)[7] SSH: Session 1: Sent packet SSH_MSG_CHANNEL_SUCCESS (48 bytes).
...