[Fixed in 1.8.2] Araknis switch not discovering/backing up

Unimus support forum
Post Reply
JAz
Posts: 37
Joined: Thu Apr 26, 2018 11:06 pm

Tue Jun 26, 2018 5:32 pm

I've bound an ssh credential but I get the error "ssh_known_credentials_refused".
Not sure if I have to configure this differently than any others?

thx.
User avatar
Tomas
Posts: 607
Joined: Sat Jun 25, 2016 12:33 pm

Tue Jun 26, 2018 5:35 pm

Hi,

It should just work if the bound credentials are correct.

Can you please run Unimus in debug mode and send me a log of the discovery run on this switch?
Alternatively, we would be happy to do a Webex session to look at this issue more in detail.
JAz
Posts: 37
Joined: Thu Apr 26, 2018 11:06 pm

Tue Jun 26, 2018 10:25 pm

Tomas wrote:
Tue Jun 26, 2018 5:35 pm
Hi,

It should just work if the bound credentials are correct.

Can you please run Unimus in debug mode and send me a log of the discovery run on this switch?
Alternatively, we would be happy to do a Webex session to look at this issue more in detail.
I tested manual login with putty so I know bound creds are right.
How to put Unimus into debug?
User avatar
Tomas
Posts: 607
Joined: Sat Jun 25, 2016 12:33 pm

Tue Jun 26, 2018 10:35 pm

On Linux:

Code: Select all

sudo su
service unimus stop
cd /opt/unimus
java -jar Unimus.jar \
--logging.level.net.unimus.core=TRACE \
--unimus.core.echo-ssh=TRUE \
--unimus.core.echo-telnet=TRUE
On Windows:

Code: Select all

1) Download .jar distribution:
   https://unimus.net/download.html
2) Stop Unimus service
   If you are running the Portable version, skip this
3) Open an admin command prompt
4) change to folder where Unimus.jar was downloaded
5) Run "java -jar Unimus.jar --logging.level.net.unimus.core=TRACE --unimus.core.echo-ssh=TRUE --unimus.core.echo-telnet=TRUE"
6) Logs should be in the command prompt window
JAz
Posts: 37
Joined: Thu Apr 26, 2018 11:06 pm

Wed Jun 27, 2018 12:46 am

I'm assuming you wanted the output from the console..

Code: Select all

2018-06-26 20:13:27.578  INFO 53231 --- [nio-8085-exec-9] net.unimus.service.DeviceService         : Attempt to run 1 discover(y/ies)
2018-06-26 20:13:27.584  INFO 53231 --- [nio-8085-exec-9] net.unimus.business.core.CoreClientImpl  : Discovering 1 devices
2018-06-26 20:13:27.595 DEBUG 53231 --- [nio-8085-exec-9] net.unimus.core.api.CoreImpl             : Received DiscoveryBatchRequest(correlationId=79b8f04f-2478-40f1-9517-4a95eb932c23, undiscoveredDevices=[UndiscoveredDevice(id=1, address=192.168.88.2, boundCredential=Credential{id=2, username='araknis', password = 20 character(s)}, boundEnablePassword=null)], commonCredentials=[Credential{id=0, username='admin', SSH key = 1675 character(s)}, Credential{id=2, username='araknis', password = 20 character(s)}, Credential{id=3, username='super', password = 15 character(s)}], commonEnablePasswords=[], connectors=[ConnectorConfig(connectorType=SSH, ports=[Port(id=4, portNumber=21220), Port(id=0, portNumber=22), Port(id=5, portNumber=21222)])], size=1)
2018-06-26 20:13:27.607 DEBUG 53231 --- [    discovery-3] net.unimus.core.api.CoreImpl             : Discovering UndiscoveredDevice(id=1, address=192.168.88.2, boundCredential=Credential{id=2, username='araknis', password = 20 character(s)}, boundEnablePassword=null)
2018-06-26 20:13:27.608 DEBUG 53231 --- [    discovery-3] n.u.c.s.cli.CliDiscoveryServiceImpl      : Discovering available SSH port on '192.168.88.2'
2018-06-26 20:13:27.608 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Checking ssh availability on 192.168.88.2:21220 within timeout 10000s
2018-06-26 20:13:27.609 DEBUG 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Failed to connect SSH to 192.168.88.2:21220 reason 'Connection refused (Connection refused)'.
2018-06-26 20:13:27.609 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Checking ssh availability on 192.168.88.2:22 within timeout 10000s
SSH-2.0-OpenSSH_6.2
2018-06-26 20:13:27.694 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Closing expect session
2018-06-26 20:13:27.695 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Closing TCP socket connection
2018-06-26 20:13:27.695 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Ssh available on '192.168.88.2'
2018-06-26 20:13:27.695 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Checking ssh availability on 192.168.88.2:21222 within timeout 10000s
2018-06-26 20:13:27.696 DEBUG 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Failed to connect SSH to 192.168.88.2:21222 reason 'Connection refused (Connection refused)'.
2018-06-26 20:13:27.697 TRACE 53231 --- [    discovery-3] n.u.c.s.cli.CliDiscoveryServiceImpl      : SSH on '192.168.88.2' discovered on port 'Port(id=0, portNumber=22)'
2018-06-26 20:13:27.697 DEBUG 53231 --- [    discovery-3] n.u.c.s.cli.CliDiscoveryServiceImpl      : Discovering usable credentials on '192.168.88.2'
2018-06-26 20:13:27.697 TRACE 53231 --- [    discovery-3] n.u.c.s.cli.CliDiscoveryServiceImpl      : Testing 1 credentials through SSH on '192.168.88.2'
2018-06-26 20:13:27.947 TRACE 53231 --- [    discovery-3] n.u.c.s.cli.CliDiscoveryServiceImpl      : Trying credentials 'Credential{id=2, username='araknis', password = 20 character(s)}' on '192.168.88.2'
2018-06-26 20:13:27.947 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Creating SSH session to 192.168.88.2:22 with 'Credential{id=2, username='araknis', password = 20 character(s)}', connectTimeout 10000
2018-06-26 20:13:29.149 TRACE 53231 --- [    discovery-3] n.unimus.core.cli.login.CliLoginHandler  : Entering step 1 of CLI login handler, counter: 1












        Welcome to Layer 2 Managed Switch












  Press <Enter> to continue...
2018-06-26 20:13:29.189 TRACE 53231 --- [    discovery-3] n.unimus.core.cli.login.CliLoginHandler  : Entering step 1 of CLI login handler, counter: 2
Username: 2018-06-26 20:13:29.681 TRACE 53231 --- [    discovery-3] n.unimus.core.cli.login.CliLoginHandler  : Sending username to '192.168.88.2
2018-06-26 20:13:29.682 TRACE 53231 --- [    discovery-3] n.unimus.core.cli.login.CliLoginHandler  : Entering step 2 of CLI login handler

% Authentication Failed

Username: 2018-06-26 20:13:29.687 TRACE 53231 --- [    discovery-3] n.unimus.core.cli.login.CliLoginHandler  : Sending username to '192.168.88.2
2018-06-26 20:13:29.687 TRACE 53231 --- [    discovery-3] n.unimus.core.cli.login.CliLoginHandler  : Entering step 3 of CLI login handler
araknis
araknis
Password: 2018-06-26 20:13:29.705 TRACE 53231 --- [    discovery-3] n.unimus.core.cli.login.CliLoginHandler  : Sending password to '192.168.88.2
2018-06-26 20:13:29.706 TRACE 53231 --- [    discovery-3] n.unimus.core.cli.login.CliLoginHandler  : Entering step 4 of CLI login handler, counter: 1
*******
jjQU************iGae
% Authentication Failed

Username: 2018-06-26 20:13:29.731 DEBUG 53231 --- [    discovery-3] n.unimus.core.cli.login.CliLoginHandler  : Failed to authenticate to 192.168.88.2:22 - invalid credentials
2018-06-26 20:13:29.732 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Closing expect session
2018-06-26 20:13:29.734 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Closing SSH shell channel
2018-06-26 20:13:29.735 TRACE 53231 --- [    discovery-3] n.u.core.service.cli.ssh.SshConnector    : Closing SSH session
2018-06-26 20:13:29.736 DEBUG 53231 --- [    discovery-3] n.u.c.s.cli.CliDiscoveryServiceImpl      : Could not login to SSH on '192.168.88.2' with any of available credentials
I anonymized the password, otherwise verbatim

I note that this is one of those sessions where you connect, it asks you for a username, you input, hit enter and then you're again presented with a username and then password prompt. It seems the second user/pass is the relevant one. The first one is like a throwaway of some sort. Is this maybe where the break lies?

edit-
Scratch that last bit. understanding the logs better, looks like user and pass are getting sent in the right place it's just failing auth. I'm out of idea :oops:
User avatar
Tomas
Posts: 607
Joined: Sat Jun 25, 2016 12:33 pm

Wed Jun 27, 2018 8:36 am

According to the log, it seems that Unimus is doing everything correctly, the device is however refusing the login.

What is strange is that even after the first username, it already outputs "% Authentication Failed".
As you can see in the log, Unimus does attempt to provide username and password the second time, but again gets "% Authentication Failed".

Probably the next step would be doing a Webex session to look at this more in details.
Please contact me over PM or email to work out the details.

Thanks!
User avatar
Tomas
Posts: 607
Joined: Sat Jun 25, 2016 12:33 pm

Thu Jul 26, 2018 11:49 am

Update:
We have finally managed to solve this issue.
Araknis switches were outputting "Press any key to continue..." but were really ignoring this and continuing with the login sequence anyway. This caused a state desync in Unimus, since it was expecting the device to wait for a key press.

Fix will be released in 1.8.2.
JAz
Posts: 37
Joined: Thu Apr 26, 2018 11:06 pm

Thu Jul 26, 2018 7:15 pm

Tomas wrote:
Thu Jul 26, 2018 11:49 am
Update:
We have finally managed to solve this issue.
Araknis switches were outputting "Press any key to continue..." but were really ignoring this and continuing with the login sequence anyway. This caused a state desync in Unimus, since it was expecting the device to wait for a key press.

Fix will be released in 1.8.2.
Excellent news Tomas. Impressive as always! Thank you 8-)
JAz
Posts: 37
Joined: Thu Apr 26, 2018 11:06 pm

Wed Aug 22, 2018 10:50 pm

Tomas wrote:
Thu Jul 26, 2018 11:49 am
Update:
We have finally managed to solve this issue.
Araknis switches were outputting "Press any key to continue..." but were really ignoring this and continuing with the login sequence anyway. This caused a state desync in Unimus, since it was expecting the device to wait for a key press.

Fix will be released in 1.8.2.
Hate to be the bearer of bad news but not fixed :(

From the Dashboard page the log gives "ssh_known_credentials_refused"

Put Unimus into debug and this is what I got:

Code: Select all

2018-08-22 18:36:40.715  INFO 5424 --- [nio-8085-exec-7] net.unimus.service.DeviceService         : Backup of 1 device(s)
2018-08-22 18:36:40.716  INFO 5424 --- [nio-8085-exec-7] net.unimus.business.core.CoreClientImpl  : Backing-up 1 device(s)
2018-08-22 18:36:40.741  INFO 5424 --- [nio-8085-exec-7] net.unimus.business.core.CoreClientImpl  : Discovering 1 devices
2018-08-22 18:36:40.753 DEBUG 5424 --- [nio-8085-exec-7] net.unimus.core.api.CoreImpl             : Received DiscoveryBatchRequest(correlationId=f4ec13c7-fdc0-40a8-97c6-44119045fa94, undiscoveredDevices=[UndiscoveredDevice(id=3, address=192.168.88.2, boundCredential=Credential{id=2, username='araknis', password = 20 character(s)}, boundEnablePassword=null)], commonCredentials=[Credential{id=0, username='admin', SSH key = 1675 character(s)}, Credential{id=2, username='araknis', password = 20 character(s)}, Credential{id=3, username='super', password = 15 character(s)}], commonEnablePasswords=[EnablePassword(id=0, enablePassword=jjQU8fFevwhVfM6BiGae)], connectors=[ConnectorConfig(connectorType=SSH, ports=[Port(id=4, portNumber=21220), Port(id=0, portNumber=22), Port(id=5, portNumber=21222)])])
2018-08-22 18:36:40.761 DEBUG 5424 --- [    discovery-2] net.unimus.core.api.CoreImpl             : Discovering UndiscoveredDevice(id=3, address=192.168.88.2, boundCredential=Credential{id=2, username='araknis', password = 20 character(s)}, boundEnablePassword=null)
2018-08-22 18:36:40.761 DEBUG 5424 --- [    discovery-2] n.u.c.s.d.CliDiscoveryServiceImpl        : Discovering available SSH port on '192.168.88.2'
2018-08-22 18:36:40.761 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Checking ssh availability on 192.168.88.2:21220 within timeout 10000s
2018-08-22 18:36:40.770 DEBUG 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Failed to connect SSH to 192.168.88.2:21220 reason 'Connection refused (Connection refused)'.
2018-08-22 18:36:40.771 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Checking ssh availability on 192.168.88.2:22 within timeout 10000s
SSH-2.0-OpenSSH_6.2
2018-08-22 18:36:40.858 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Closing expect session
2018-08-22 18:36:40.858 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Closing TCP socket connection
2018-08-22 18:36:40.858 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Ssh available on '192.168.88.2'
2018-08-22 18:36:40.859 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Checking ssh availability on 192.168.88.2:21222 within timeout 10000s
2018-08-22 18:36:40.861 DEBUG 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Failed to connect SSH to 192.168.88.2:21222 reason 'Connection refused (Connection refused)'.
2018-08-22 18:36:40.861 TRACE 5424 --- [    discovery-2] n.u.c.s.d.CliDiscoveryServiceImpl        : SSH on '192.168.88.2' discovered on port 'Port(id=0, portNumber=22)'
2018-08-22 18:36:40.862 DEBUG 5424 --- [    discovery-2] n.u.c.s.d.CliDiscoveryServiceImpl        : Discovering usable credentials on '192.168.88.2'
2018-08-22 18:36:40.862 TRACE 5424 --- [    discovery-2] n.u.c.s.d.CliDiscoveryServiceImpl        : Testing 1 credentials through SSH on '192.168.88.2'
2018-08-22 18:36:41.113 TRACE 5424 --- [    discovery-2] n.u.c.s.d.CliDiscoveryServiceImpl        : Trying credentials 'Credential{id=2, username='araknis', password = 20 character(s)}' on '192.168.88.2'
2018-08-22 18:36:41.113 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Creating SSH session to 192.168.88.2:22 with 'Credential{id=2, username='araknis', password = 20 character(s)}', connectTimeout 10000
2018-08-22 18:36:42.200 TRACE 5424 --- [    discovery-2] n.unimus.core.cli.login.CliLoginHandler  : Entering step 1 of CLI login handler, counter: 1












        Welcome to Layer 2 Managed Switch












  Press <Enter> to continue...
2018-08-22 18:36:42.229 TRACE 5424 --- [    discovery-2] n.unimus.core.cli.login.CliLoginHandler  : Entering step 1 of CLI login handler, counter: 2
Username: 2018-08-22 18:36:42.671 TRACE 5424 --- [    discovery-2] n.unimus.core.cli.login.CliLoginHandler  : Sending username to '192.168.88.2
2018-08-22 18:36:42.671 TRACE 5424 --- [    discovery-2] n.unimus.core.cli.login.CliLoginHandler  : Entering step 2 of CLI login handler

araknis
% Authentication Failed

Username: 2018-08-22 18:36:42.677 DEBUG 5424 --- [    discovery-2] n.unimus.core.cli.login.CliLoginHandler  : Failed to authenticate to 192.168.88.2:22 - invalid credentials
2018-08-22 18:36:42.679 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Closing expect session
2018-08-22 18:36:42.684 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Closing SSH shell channel
2018-08-22 18:36:42.689 TRACE 5424 --- [    discovery-2] n.u.core.service.cli.ssh.SshConnector    : Closing SSH session
2018-08-22 18:36:42.690 DEBUG 5424 --- [    discovery-2] n.u.c.s.d.CliDiscoveryServiceImpl        : Could not login to SSH on '192.168.88.2' with any of available credentials
Username is 'araknis'
This is one of those logins that asks for the username twice..


And here is a PuTTY session log (just logged in using same credentials and logged right out.) Note the repeated username prompt.

Code: Select all

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2018.08.22 18:43:08 =~=~=~=~=~=~=~=~=~=~=~=
login as: araknis












        Welcome to Layer 2 Managed Switch












  Press <Enter> to continue...
[H[JUsername: araknis
Password: ********************
FHS-Core-310-NEW# exit
FHS-Core-310-NEW> exit
Post Reply