Tipps zur Fehlerbehebung bei SSH-Problemen mit proprietärer Software

Tipps zur Fehlerbehebung bei SSH-Problemen mit proprietärer Software

Ich habe ein Problem beim Einrichten eines Kanals mit einem von uns gekauften Hardwareteil. Ich kann mich per SSH mit dem VXworks-Betriebssystem verbinden, indem ich sowohl Putty (unter Windows) als auch die CLI von Ubuntu verwende. Wenn ich jedoch Befehle mit Ruby oder Python an die Hardware sende, erhalte ich die Meldung „Verbindung vom Remote-Host geschlossen“.

Ich habe Folgendes gemacht:

  1. Habe verschiedene Programmiersprachen mit unterschiedlichen Implementierungen auf verschiedenen Betriebssystemen ausprobiert
  2. Habe verschiedene Versionen von Ruby und Net::SSH ausprobiert, darunter auch die 4.0 Alpha
  3. Erlaubter Port 22 Zugriff auf die Hardware, auf der Hardware
  4. Hinzufügen eines Timeouts
  5. Spezifizieren bestimmter Kex-Schlüssel
  6. Einengung des KEXIT (ich glaube, so heißt er)
  7. Habe die Ingenieure kontaktiert. Sie glauben nicht, dass es an ihnen liegt, aber sie geben es weiter.
  8. Python-Skript in secureCRT, das tatsächlich funktioniert hat.

Was sollte ich als nächstes überprüfen? Mir gehen die Ideen aus.


Ein Ingenieur sagte:

„Die Skripte müssen eine Pufferung zwischen den Befehlen haben. Ich habe securecrt für ein Skripting verwendet.“

Hier ist das secureCRT-Skript, mit dem ich eine Verbindung zum Gerät herstellen konnte. Ich bin nicht ganz sicher, ob dies relevant ist:

host = "x.x.x.x"
user = "admin"

def main():
    # Prompt for a password instead of embedding it in a script...
    #
    passwd = crt.Dialog.Prompt("Enter password for " + host, "Login", "", True)

    # Build a command-line string to pass to the Connect method.
    cmd = "/SSH2 /L %s /PASSWORD %s /C 3DES /M MD5 %s" % (user, passwd, host)
    crt.Session.Connect(cmd)


main()

Hier ist das Protokoll des VXworks-Systems:

logged out from slot 1
    [82]: JAN 23 05:13:17: alert  : 1/1/1028: clitask1: User [email protected] logged in on slot 1
    [83]: JAN 23 05:17:41: debug  : 1/1/1038: sshs: tSshServer: accept socket active.
    [84]: JAN 23 05:17:41: debug  : 1/1/1038: sshs: tSshServer: session index = 0 remote IP x.x.x.x.
    [85]: JAN 23 05:17:41: debug  : 1/1/1038: sshs: connInstance = 4218
    [86]: JAN 23 05:17:42: debug  : 1/1/1078: sshs: AuthPassword Callback: conn: 4218: user = admin
    [87]: JAN 23 05:17:42: alert  : 1/1/1078: clitask0: User [email protected] logged in on slot 1
    [88]: JAN 23 05:17:42: debug  : 1/1/1078: sshs: RxCallback: session: 0 event: OPEN
    [89]: JAN 23 05:17:42: debug  : 1/1/1078: sshs: SshInTask: after while() loop, status = -6911, cleanUp = 0
    [90]: JAN 23 05:17:42: debug  : 1/1/1078: sshs: _SshExit(0, 0) called
    [91]: JAN 23 05:19:43: debug  : 1/1/1038: sshs: tSshServer: accept socket active.
    [92]: JAN 23 05:19:43: debug  : 1/1/1038: sshs: tSshServer: session index = 0 remote IP x.x.x.x.
    [93]: JAN 23 05:19:43: debug  : 1/1/1038: sshs: connInstance = 4219
    [94]: JAN 23 05:19:46: debug  : 1/1/1078: sshs: AuthPassword Callback: conn: 4219: user = admin
    [95]: JAN 23 05:19:46: alert  : 1/1/1078: clitask0: User [email protected] logged in on slot 1
    [96]: JAN 23 05:19:46: debug  : 1/1/1078: sshs: RxCallback: session: 0 event: OPEN
    [97]: JAN 23 05:19:46: debug  : 1/1/1078: sshs: SshInTask: after while() loop, status = -6911, cleanUp = 0
    [98]: JAN 23 05:19:46: debug  : 1/1/1078: sshs: _SshExit(0, 0) called
    [99]: JAN 23 05:21:55: alert  : 1/1/1028: clitask1: User [email protected] logged out from slot 1
    [100]: JAN 23 05:23:29: alert  : 1/1/1028: clitask1: User [email protected] logged in on slot 1

Hier ist das Protokoll von Net::SSH

[2016-05-02T13:41:48.064959 #89562] DEBUG -- net.ssh.transport.session[11a9720]: establishing connection to 10.100.0.31:22
D, [2016-05-02T13:41:48.066315 #89562] DEBUG -- net.ssh.transport.session[11a9720]: connection established
I, [2016-05-02T13:41:48.066422 #89562]  INFO -- net.ssh.transport.server_version[11a8eec]: negotiating protocol version
D, [2016-05-02T13:41:48.066440 #89562] DEBUG -- net.ssh.transport.server_version[11a8eec]: local is `SSH-2.0-Ruby/Net::SSH_4.0.0.alpha3 x86_64-linux'
D, [2016-05-02T13:41:48.069158 #89562] DEBUG -- net.ssh.transport.server_version[11a8eec]: remote is `SSH-2.0-Mocana SSH'
D, [2016-05-02T13:41:48.070131 #89562] DEBUG -- socket[11a934c]: read 424 bytes
D, [2016-05-02T13:41:48.070230 #89562] DEBUG -- socket[11a934c]: received packet nr 0 type 20 len 420
I, [2016-05-02T13:41:48.070288 #89562]  INFO -- net.ssh.transport.algorithms[11a85f0]: got KEXINIT from server
I, [2016-05-02T13:41:48.070350 #89562]  INFO -- net.ssh.transport.algorithms[11a85f0]: sending KEXINIT
D, [2016-05-02T13:41:48.070450 #89562] DEBUG -- socket[11a934c]: queueing packet nr 0 type 20 len 1156
D, [2016-05-02T13:41:48.070574 #89562] DEBUG -- socket[11a934c]: sent 1160 bytes
I, [2016-05-02T13:41:48.070615 #89562]  INFO -- net.ssh.transport.algorithms[11a85f0]: negotiating algorithms
D, [2016-05-02T13:41:48.070694 #89562] DEBUG -- net.ssh.transport.algorithms[11a85f0]: negotiated:
* kex: diffie-hellman-group1-sha1
* host_key: ssh-dss
* encryption_server: aes128-cbc
* encryption_client: aes128-cbc
* hmac_client: hmac-sha1
* hmac_server: hmac-sha1
* compression_client: none
* compression_server: none
* language_client: 
* language_server: 
D, [2016-05-02T13:41:48.070740 #89562] DEBUG -- net.ssh.transport.algorithms[11a85f0]: exchanging keys
D, [2016-05-02T13:41:48.071565 #89562] DEBUG -- socket[11a934c]: queueing packet nr 1 type 30 len 140
D, [2016-05-02T13:41:48.071659 #89562] DEBUG -- socket[11a934c]: sent 144 bytes
D, [2016-05-02T13:41:48.276487 #89562] DEBUG -- socket[11a934c]: read 448 bytes
D, [2016-05-02T13:41:48.276613 #89562] DEBUG -- socket[11a934c]: received packet nr 1 type 31 len 444
D, [2016-05-02T13:41:48.277173 #89562] DEBUG -- socket[11a934c]: queueing packet nr 2 type 21 len 20
D, [2016-05-02T13:41:48.277280 #89562] DEBUG -- socket[11a934c]: sent 24 bytes
D, [2016-05-02T13:41:48.280778 #89562] DEBUG -- socket[11a934c]: read 16 bytes
D, [2016-05-02T13:41:48.280829 #89562] DEBUG -- socket[11a934c]: received packet nr 2 type 21 len 12
D, [2016-05-02T13:41:48.281017 #89562] DEBUG -- net.ssh.authentication.session[11d6f40]: beginning authentication of `admin'
D, [2016-05-02T13:41:48.281089 #89562] DEBUG -- socket[11a934c]: queueing packet nr 3 type 5 len 28
D, [2016-05-02T13:41:48.281231 #89562] DEBUG -- socket[11a934c]: sent 52 bytes
D, [2016-05-02T13:41:48.282232 #89562] DEBUG -- socket[11a934c]: read 52 bytes
D, [2016-05-02T13:41:48.282290 #89562] DEBUG -- socket[11a934c]: received packet nr 3 type 6 len 28
D, [2016-05-02T13:41:48.282386 #89562] DEBUG -- net.ssh.authentication.session[11d6f40]: trying none
D, [2016-05-02T13:41:48.282458 #89562] DEBUG -- socket[11a934c]: queueing packet nr 4 type 50 len 44
D, [2016-05-02T13:41:48.282537 #89562] DEBUG -- socket[11a934c]: sent 68 bytes
D, [2016-05-02T13:41:48.284239 #89562] DEBUG -- socket[11a934c]: read 52 bytes
D, [2016-05-02T13:41:48.284306 #89562] DEBUG -- socket[11a934c]: received packet nr 4 type 51 len 28
D, [2016-05-02T13:41:48.284352 #89562] DEBUG -- net.ssh.authentication.session[11d6f40]: allowed methods: password
D, [2016-05-02T13:41:48.284387 #89562] DEBUG -- net.ssh.authentication.methods.none[11dfcf8]: none failed
D, [2016-05-02T13:41:48.284420 #89562] DEBUG -- net.ssh.authentication.session[11d6f40]: trying password
D, [2016-05-02T13:41:48.284489 #89562] DEBUG -- socket[11a934c]: queueing packet nr 5 type 50 len 60
D, [2016-05-02T13:41:48.284569 #89562] DEBUG -- socket[11a934c]: sent 84 bytes
D, [2016-05-02T13:41:48.295419 #89562] DEBUG -- socket[11a934c]: read 36 bytes
D, [2016-05-02T13:41:48.295559 #89562] DEBUG -- socket[11a934c]: received packet nr 5 type 52 len 12
D, [2016-05-02T13:41:48.295638 #89562] DEBUG -- net.ssh.authentication.methods.password[11de8a8]: password succeeded
D, [2016-05-02T13:41:48.295769 #89562] DEBUG -- socket[11a934c]: queueing packet nr 6 type 90 len 44
D, [2016-05-02T13:41:48.295911 #89562] DEBUG -- socket[11a934c]: sent 68 bytes
D, [2016-05-02T13:41:48.297023 #89562] DEBUG -- socket[11a934c]: read 52 bytes
D, [2016-05-02T13:41:48.297124 #89562] DEBUG -- socket[11a934c]: received packet nr 6 type 91 len 28
I, [2016-05-02T13:41:48.297203 #89562]  INFO -- net.ssh.connection.session[11e3f88]: channel_open_confirmation: 0 85460946 1000 1000
I, [2016-05-02T13:41:48.297353 #89562]  INFO -- net.ssh.connection.channel[11e3df8]: sending channel request "env"
D, [2016-05-02T13:41:48.297444 #89562] DEBUG -- socket[11a934c]: queueing packet nr 7 type 98 len 44
I, [2016-05-02T13:41:48.297579 #89562]  INFO -- net.ssh.connection.channel[11e3df8]: sending channel request "exec"
D, [2016-05-02T13:41:48.297637 #89562] DEBUG -- socket[11a934c]: queueing packet nr 8 type 98 len 28
D, [2016-05-02T13:41:48.297871 #89562] DEBUG -- socket[11a934c]: sent 120 bytes
D, [2016-05-02T13:41:49.297172 #89562] DEBUG -- socket[11a934c]: read 140 bytes
D, [2016-05-02T13:41:49.297469 #89562] DEBUG -- socket[11a934c]: read 0 bytes
I, [2016-05-02T13:41:49.297762 #89562]  INFO -- net.ssh.connection.session[11e3f88]: closing remaining channels (1 open)
D, [2016-05-02T13:41:49.297895 #89562] DEBUG -- socket[11a934c]: read 0 bytes
Net::SSH::Disconnect: connection closed by remote host

verwandte Informationen