oxidized icon indicating copy to clipboard operation
oxidized copied to clipboard

Issue with Backuping MLNXOS Devices Using Oxidized

Open graby0 opened this issue 1 year ago • 7 comments

Hello,

In my infrastructure, I manage a large number of network devices that I back up using Oxidized. However, I am encountering an issue with backing up devices running the MLNXOS system.

From the Linux shell, I am able to connect to the switch via SSH and execute all the necessary commands without any problems.

However, the following error messages appear in the Oxidized logs:

W, [2024-11-14T10:29:09.589014 #144957]  WARN -- : IP raised Net::SSH::AuthenticationFailed with msg "Authentication failed for user backup@IP"
W, [2024-11-14T10:29:10.372208 #144957]  WARN -- : CMP/CMP-PUL-SWC02-M2 status no_connection, retry attempt 1
W, [2024-11-14T10:29:10.591862 #144957]  WARN -- : IP raised Net::SSH::AuthenticationFailed with msg "Authentication failed for user backup@IP"
W, [2024-11-14T10:29:11.374222 #144957]  WARN -- : CMP/CMP-PUL-SWC02-M2 status no_connection, retries exhausted, giving up


Log in debug level:
D, [2024-12-16T15:09:28.402377 #19416] DEBUG -- : lib/oxidized/worker.rb: Added Switch_name to the job queue
D, [2024-12-16T15:09:28.402410 #19416] DEBUG -- : lib/oxidized/worker.rb: 1 jobs running in parallel
D, [2024-12-16T15:09:28.402549 #19416] DEBUG -- : lib/oxidized/job.rb: Starting fetching process for Switch_name at 2024-12-16 14:09:28 UTC
D, [2024-12-16T15:09:28.402708 #19416] DEBUG -- : lib/oxidized/input/ssh.rb: Connecting to Switch_name
D, [2024-12-16T15:09:28.402968 #19416] DEBUG -- : AUTH METHODS::["none", "publickey", "password"]
D, [2024-12-16T15:09:28.403529 #19416] DEBUG -- net.ssh.transport.session[744]: establishing connection to IP:22
D, [2024-12-16T15:09:28.405269 #19416] DEBUG -- net.ssh.transport.session[744]: connection established
I, [2024-12-16T15:09:28.405317 #19416]  INFO -- net.ssh.transport.server_version[758]: negotiating protocol version
D, [2024-12-16T15:09:28.405328 #19416] DEBUG -- net.ssh.transport.server_version[758]: local is `SSH-2.0-Ruby/Net::SSH_7.2.1 x86_64-linux'
D, [2024-12-16T15:09:28.509251 #19416] DEBUG -- net.ssh.transport.server_version[758]: remote is `SSH-2.0-OpenSSH_8.0'
I, [2024-12-16T15:09:28.509667 #19416]  INFO -- net.ssh.transport.algorithms[76c]: sending KEXINIT
D, [2024-12-16T15:09:28.509781 #19416] DEBUG -- socket[780]: queueing packet nr 0 type 20 len 1436
D, [2024-12-16T15:09:28.509846 #19416] DEBUG -- socket[780]: sent 1440 bytes
D, [2024-12-16T15:09:28.510347 #19416] DEBUG -- socket[780]: read 616 bytes
D, [2024-12-16T15:09:28.510404 #19416] DEBUG -- socket[780]: received packet nr 0 type 20 len 612
I, [2024-12-16T15:09:28.510426 #19416]  INFO -- net.ssh.transport.algorithms[76c]: got KEXINIT from server
I, [2024-12-16T15:09:28.510463 #19416]  INFO -- net.ssh.transport.algorithms[76c]: negotiating algorithms
D, [2024-12-16T15:09:28.510517 #19416] DEBUG -- net.ssh.transport.algorithms[76c]: negotiated:
* kex: diffie-hellman-group14-sha256
* host_key: ssh-rsa
* encryption_server: aes256-ctr
* encryption_client: aes256-ctr
* hmac_client: [email protected]
* hmac_server: [email protected]
* compression_client: none
* compression_server: none
* language_client:
* language_server:
D, [2024-12-16T15:09:28.510528 #19416] DEBUG -- net.ssh.transport.algorithms[76c]: exchanging keys
D, [2024-12-16T15:09:28.512934 #19416] DEBUG -- socket[780]: queueing packet nr 1 type 30 len 268
D, [2024-12-16T15:09:28.512997 #19416] DEBUG -- socket[780]: sent 272 bytes
D, [2024-12-16T15:09:28.548316 #19416] DEBUG -- socket[780]: read 1104 bytes
D, [2024-12-16T15:09:28.548450 #19416] DEBUG -- socket[780]: received packet nr 1 type 31 len 1084
D, [2024-12-16T15:09:28.551124 #19416] DEBUG -- socket[780]: queueing packet nr 2 type 21 len 20
D, [2024-12-16T15:09:28.551214 #19416] DEBUG -- socket[780]: sent 24 bytes
D, [2024-12-16T15:09:28.551254 #19416] DEBUG -- socket[780]: received packet nr 2 type 21 len 12
D, [2024-12-16T15:09:28.551479 #19416] DEBUG -- net.ssh.authentication.session[794]: beginning authentication of `backup'
D, [2024-12-16T15:09:28.551529 #19416] DEBUG -- socket[780]: using encrypt-then-mac
D, [2024-12-16T15:09:28.551568 #19416] DEBUG -- socket[780]: queueing packet nr 3 type 5 len 32
D, [2024-12-16T15:09:28.551584 #19416] DEBUG -- socket[780]: sent 100 bytes
D, [2024-12-16T15:09:28.594341 #19416] DEBUG -- socket[780]: read 100 bytes
D, [2024-12-16T15:09:28.594520 #19416] DEBUG -- socket[780]: received packet nr 3 type 6 len 32
D, [2024-12-16T15:09:28.594604 #19416] DEBUG -- net.ssh.authentication.session[794]: trying none
D, [2024-12-16T15:09:28.594685 #19416] DEBUG -- socket[780]: using encrypt-then-mac
D, [2024-12-16T15:09:28.594728 #19416] DEBUG -- socket[780]: queueing packet nr 4 type 50 len 48
D, [2024-12-16T15:09:28.594786 #19416] DEBUG -- socket[780]: sent 116 bytes
D, [2024-12-16T15:09:28.604548 #19416] DEBUG -- socket[780]: read 232 bytes
D, [2024-12-16T15:09:28.604725 #19416] DEBUG -- socket[780]: received packet nr 4 type 53 len 48
I, [2024-12-16T15:09:28.604770 #19416]  INFO -- net.ssh.authentication.session[794]: HPE Management Console

D, [2024-12-16T15:09:28.604817 #19416] DEBUG -- socket[780]: received packet nr 5 type 51 len 48
D, [2024-12-16T15:09:28.604850 #19416] DEBUG -- net.ssh.authentication.session[794]: allowed methods: publickey,keyboard-interactive
D, [2024-12-16T15:09:28.604881 #19416] DEBUG -- net.ssh.authentication.methods.none[7a8]: none failed
D, [2024-12-16T15:09:28.604904 #19416] DEBUG -- net.ssh.authentication.session[794]: trying publickey
D, [2024-12-16T15:09:28.605117 #19416] DEBUG -- net.ssh.authentication.agent[7bc]: connecting to ssh-agent
E, [2024-12-16T15:09:28.605153 #19416] ERROR -- net.ssh.authentication.agent[7bc]: could not connect to ssh-agent: Agent not configured
D, [2024-12-16T15:09:28.605232 #19416] DEBUG -- net.ssh.authentication.methods.publickey[7e4]: trying publickey (ca:02:c0:81:b1:e7:1f:43:ea:d3:65:82:92:25:c9:37) alg rsa-sha2-256
D, [2024-12-16T15:09:28.605297 #19416] DEBUG -- socket[780]: using encrypt-then-mac
D, [2024-12-16T15:09:28.605335 #19416] DEBUG -- socket[780]: queueing packet nr 5 type 50 len 368
D, [2024-12-16T15:09:28.605383 #19416] DEBUG -- socket[780]: sent 436 bytes
D, [2024-12-16T15:09:28.615347 #19416] DEBUG -- socket[780]: read 116 bytes
D, [2024-12-16T15:09:28.615494 #19416] DEBUG -- socket[780]: received packet nr 6 type 51 len 48
D, [2024-12-16T15:09:28.615550 #19416] DEBUG -- net.ssh.authentication.session[794]: allowed methods: publickey,keyboard-interactive
D, [2024-12-16T15:09:28.615576 #19416] DEBUG -- net.ssh.authentication.methods.publickey[7e4]: trying publickey (ca:02:c0:81:b1:e7:1f:43:ea:d3:65:82:92:25:c9:37) alg ssh-rsa
D, [2024-12-16T15:09:28.615656 #19416] DEBUG -- socket[780]: using encrypt-then-mac
D, [2024-12-16T15:09:28.615861 #19416] DEBUG -- socket[780]: queueing packet nr 6 type 50 len 352
D, [2024-12-16T15:09:28.615938 #19416] DEBUG -- socket[780]: sent 420 bytes
D, [2024-12-16T15:09:28.625840 #19416] DEBUG -- socket[780]: read 116 bytes
D, [2024-12-16T15:09:28.626012 #19416] DEBUG -- socket[780]: received packet nr 7 type 51 len 48
D, [2024-12-16T15:09:28.626074 #19416] DEBUG -- net.ssh.authentication.session[794]: allowed methods: publickey,keyboard-interactive
E, [2024-12-16T15:09:28.626106 #19416] ERROR -- net.ssh.authentication.session[794]: all authorization methods failed (tried none, publickey)
W, [2024-12-16T15:09:28.626194 #19416]  WARN -- : IP raised Net::SSH::AuthenticationFailed with msg "Authentication failed for user backup@IP"
D, [2024-12-16T15:09:28.626221 #19416] DEBUG -- : lib/oxidized/node.rb: Oxidized::SSH failed for Switch_name
D, [2024-12-16T15:09:28.626243 #19416] DEBUG -- : lib/oxidized/job.rb: Config fetched for Switch_name at 2024-12-16 14:09:28 UTC
W, [2024-12-16T15:09:29.403547 #19416]  WARN -- : Switch_name status no_connection, retry attempt 1
D, [2024-12-16T15:09:29.403611 #19416] DEBUG -- : lib/oxidized/worker.rb: Jobs running: 0 of 1 - ended: 2 of 441
D, [2024-12-16T15:09:29.403647 #19416] DEBUG -- : lib/oxidized/worker.rb: Added Switch_name to the job queue
D, [2024-12-16T15:09:29.403663 #19416] DEBUG -- : lib/oxidized/worker.rb: 1 jobs running in parallel
D, [2024-12-16T15:09:29.403725 #19416] DEBUG -- : lib/oxidized/job.rb: Starting fetching process for Switch_name at 2024-12-16 14:09:29 UTC
D, [2024-12-16T15:09:29.403871 #19416] DEBUG -- : lib/oxidized/input/ssh.rb: Connecting to Switch_name
D, [2024-12-16T15:09:29.403955 #19416] DEBUG -- : AUTH METHODS::["none", "publickey", "password"]
D, [2024-12-16T15:09:29.404500 #19416] DEBUG -- net.ssh.transport.session[7f8]: establishing connection to IP:22
D, [2024-12-16T15:09:29.406144 #19416] DEBUG -- net.ssh.transport.session[7f8]: connection established
I, [2024-12-16T15:09:29.406201 #19416]  INFO -- net.ssh.transport.server_version[80c]: negotiating protocol version
D, [2024-12-16T15:09:29.406213 #19416] DEBUG -- net.ssh.transport.server_version[80c]: local is `SSH-2.0-Ruby/Net::SSH_7.2.1 x86_64-linux'
D, [2024-12-16T15:09:29.510154 #19416] DEBUG -- net.ssh.transport.server_version[80c]: remote is `SSH-2.0-OpenSSH_8.0'
I, [2024-12-16T15:09:29.510569 #19416]  INFO -- net.ssh.transport.algorithms[820]: sending KEXINIT
D, [2024-12-16T15:09:29.510692 #19416] DEBUG -- socket[834]: queueing packet nr 0 type 20 len 1436
D, [2024-12-16T15:09:29.510744 #19416] DEBUG -- socket[834]: sent 1440 bytes
D, [2024-12-16T15:09:29.511230 #19416] DEBUG -- socket[834]: read 616 bytes
D, [2024-12-16T15:09:29.511288 #19416] DEBUG -- socket[834]: received packet nr 0 type 20 len 612
I, [2024-12-16T15:09:29.511322 #19416]  INFO -- net.ssh.transport.algorithms[820]: got KEXINIT from server
I, [2024-12-16T15:09:29.511369 #19416]  INFO -- net.ssh.transport.algorithms[820]: negotiating algorithms
D, [2024-12-16T15:09:29.511433 #19416] DEBUG -- net.ssh.transport.algorithms[820]: negotiated:
* kex: diffie-hellman-group14-sha256
* host_key: ssh-rsa
* encryption_server: aes256-ctr
* encryption_client: aes256-ctr
* hmac_client: [email protected]
* hmac_server: [email protected]
* compression_client: none
* compression_server: none
* language_client:
* language_server:
D, [2024-12-16T15:09:29.511450 #19416] DEBUG -- net.ssh.transport.algorithms[820]: exchanging keys
D, [2024-12-16T15:09:29.513696 #19416] DEBUG -- socket[834]: queueing packet nr 1 type 30 len 268
D, [2024-12-16T15:09:29.513744 #19416] DEBUG -- socket[834]: sent 272 bytes
D, [2024-12-16T15:09:29.549069 #19416] DEBUG -- socket[834]: read 1104 bytes
D, [2024-12-16T15:09:29.549252 #19416] DEBUG -- socket[834]: received packet nr 1 type 31 len 1084
D, [2024-12-16T15:09:29.551659 #19416] DEBUG -- socket[834]: queueing packet nr 2 type 21 len 20
D, [2024-12-16T15:09:29.552014 #19416] DEBUG -- socket[834]: sent 24 bytes
D, [2024-12-16T15:09:29.552063 #19416] DEBUG -- socket[834]: received packet nr 2 type 21 len 12
D, [2024-12-16T15:09:29.552298 #19416] DEBUG -- net.ssh.authentication.session[848]: beginning authentication of `backup'
D, [2024-12-16T15:09:29.552349 #19416] DEBUG -- socket[834]: using encrypt-then-mac
D, [2024-12-16T15:09:29.552392 #19416] DEBUG -- socket[834]: queueing packet nr 3 type 5 len 32
D, [2024-12-16T15:09:29.552409 #19416] DEBUG -- socket[834]: sent 100 bytes
D, [2024-12-16T15:09:29.595225 #19416] DEBUG -- socket[834]: read 100 bytes
D, [2024-12-16T15:09:29.595467 #19416] DEBUG -- socket[834]: received packet nr 3 type 6 len 32
D, [2024-12-16T15:09:29.595574 #19416] DEBUG -- net.ssh.authentication.session[848]: trying none
D, [2024-12-16T15:09:29.595671 #19416] DEBUG -- socket[834]: using encrypt-then-mac
D, [2024-12-16T15:09:29.595706 #19416] DEBUG -- socket[834]: queueing packet nr 4 type 50 len 48
D, [2024-12-16T15:09:29.595761 #19416] DEBUG -- socket[834]: sent 116 bytes
D, [2024-12-16T15:09:29.605507 #19416] DEBUG -- socket[834]: read 232 bytes
D, [2024-12-16T15:09:29.605617 #19416] DEBUG -- socket[834]: received packet nr 4 type 53 len 48
I, [2024-12-16T15:09:29.605666 #19416]  INFO -- net.ssh.authentication.session[848]: HPE Management Console

D, [2024-12-16T15:09:29.605715 #19416] DEBUG -- socket[834]: received packet nr 5 type 51 len 48
D, [2024-12-16T15:09:29.605743 #19416] DEBUG -- net.ssh.authentication.session[848]: allowed methods: publickey,keyboard-interactive
D, [2024-12-16T15:09:29.605781 #19416] DEBUG -- net.ssh.authentication.methods.none[85c]: none failed
D, [2024-12-16T15:09:29.605810 #19416] DEBUG -- net.ssh.authentication.session[848]: trying publickey
D, [2024-12-16T15:09:29.606074 #19416] DEBUG -- net.ssh.authentication.agent[870]: connecting to ssh-agent
E, [2024-12-16T15:09:29.606122 #19416] ERROR -- net.ssh.authentication.agent[870]: could not connect to ssh-agent: Agent not configured
D, [2024-12-16T15:09:29.606221 #19416] DEBUG -- net.ssh.authentication.methods.publickey[898]: trying publickey (ca:02:c0:81:b1:e7:1f:43:ea:d3:65:82:92:25:c9:37) alg rsa-sha2-256
D, [2024-12-16T15:09:29.606288 #19416] DEBUG -- socket[834]: using encrypt-then-mac
D, [2024-12-16T15:09:29.606320 #19416] DEBUG -- socket[834]: queueing packet nr 5 type 50 len 368
D, [2024-12-16T15:09:29.606353 #19416] DEBUG -- socket[834]: sent 436 bytes
D, [2024-12-16T15:09:29.616123 #19416] DEBUG -- socket[834]: read 116 bytes
D, [2024-12-16T15:09:29.616216 #19416] DEBUG -- socket[834]: received packet nr 6 type 51 len 48
D, [2024-12-16T15:09:29.616254 #19416] DEBUG -- net.ssh.authentication.session[848]: allowed methods: publickey,keyboard-interactive
D, [2024-12-16T15:09:29.616279 #19416] DEBUG -- net.ssh.authentication.methods.publickey[898]: trying publickey (ca:02:c0:81:b1:e7:1f:43:ea:d3:65:82:92:25:c9:37) alg ssh-rsa
D, [2024-12-16T15:09:29.616337 #19416] DEBUG -- socket[834]: using encrypt-then-mac
D, [2024-12-16T15:09:29.616372 #19416] DEBUG -- socket[834]: queueing packet nr 6 type 50 len 352
D, [2024-12-16T15:09:29.616406 #19416] DEBUG -- socket[834]: sent 420 bytes
D, [2024-12-16T15:09:29.626510 #19416] DEBUG -- socket[834]: read 116 bytes
D, [2024-12-16T15:09:29.626841 #19416] DEBUG -- socket[834]: received packet nr 7 type 51 len 48
D, [2024-12-16T15:09:29.627015 #19416] DEBUG -- net.ssh.authentication.session[848]: allowed methods: publickey,keyboard-interactive
E, [2024-12-16T15:09:29.627131 #19416] ERROR -- net.ssh.authentication.session[848]: all authorization methods failed (tried none, publickey)
W, [2024-12-16T15:09:29.627261 #19416]  WARN -- : IP raised Net::SSH::AuthenticationFailed with msg "Authentication failed for user backup@IP"
D, [2024-12-16T15:09:29.627287 #19416] DEBUG -- : lib/oxidized/node.rb: Oxidized::SSH failed for Switch_name
D, [2024-12-16T15:09:29.627311 #19416] DEBUG -- : lib/oxidized/job.rb: Config fetched for Switch_name at 2024-12-16 14:09:29 UTC
W, [2024-12-16T15:09:30.405218 #19416]  WARN -- : Switch_name status no_connection, retries exhausted, giving up

Switch Version (logged in from Centos7):

[oxidized@OXIDIZED oxidized]$ ssh backup@IP
HPE Management Console
Password:
Last login: Tue Dec 24 10:49:55 CET 2024 from 10.127.200.10 on pts/0
Number of total successful connections since last 1 days: 49
HPE Switch
CMP-PUL-SWC02-M2 [switch_name: standby] > enable
CMP-PUL-SWC02-M2 [switch_name standby] # show version
Product name:      Onyx
Product release:   3.10.3004
Build ID:          #1-dev
Build date:        2022-08-01 18:41:38
Target arch:       x86_64
Target hw:         x86_64
Built by:          sw-r2d2-bot@782111439e91
Version summary:   X86_64 3.10.3004 2022-08-01 18:41:38 x86_64

Product model:     x86onie
Host ID:           Host_ID
System serial num: Serial_number
System UUID:       System_UUID

Uptime:            387d 0h 49m 47.008s
CPU load averages: 0.04 / 0.07 / 0.04
Number of CPUs:    4
System memory:     2716 MB used / 5087 MB free / 7803 MB total
Swap:              0 MB used / 0 MB free / 0 MB total

The entry in the router.db file for the device does not differ from other switches that are being backed up successfully: Switch_name:group:mlnxos:IP:backup:my_password:false:22:false:false:

Additionally, I have a default model for these types of devices: /usr/local/rvm/gems/ruby-3.0.0/gems/oxidized-0.29.1/lib/oxidized/model/mlnxos.rb

For additional context, here is my setup:

  • Oxidized version: 0.29.1
  • Ruby version: 3.0.0
  • OS: CentOS Linux 7

I would appreciate any guidance on resolving this issue. If additional information is required, I’d be happy to provide it.

graby0 avatar Jan 02 '25 12:01 graby0

Updated Issue for readability

robertcheramy avatar Jan 07 '25 08:01 robertcheramy

Please try if it works with the latest Oxidized version.

robertcheramy avatar Jan 07 '25 08:01 robertcheramy

Updating Ruby from version 3.0.0 to version 3.1.4 and Oxidizez from version 0.29.1 to version 0.31 did not fix the issue.

graby0 avatar Jan 07 '25 09:01 graby0

This issue is stale because it has been open 90 days with no activity.

github-actions[bot] avatar Apr 08 '25 02:04 github-actions[bot]

Possible duplicate to #3469 . If not, the way to solve is the same as there:

Please submit a YAML simulation file.

extra/device2yaml.rb oxidized@r61 -c "show version
show inventory
enable
show running-config
exit" -o spec/model/data/mlnxos:Onyx_3.10.3004:simulation.yaml

Interact with the device (Press [space] when the pager asks to, enable will probably ask you to enter your password) and clean afterwards data you don't want to share, but leave the escape codes unchanged.

robertcheramy avatar Apr 08 '25 06:04 robertcheramy

Please test if the issue is solved by PR #3496

robertcheramy avatar Apr 21 '25 19:04 robertcheramy

PR #3496 has been merged into master. If your issue persists, please provide a new YAML Simulation file. If you issue is resolved, kindly close this issue. If there is no more activity on this issue, it will be closed after 90 days, wenn ich becomes stale.

As the model changed, here is the new command to produce a YAML simulation:

extra/device2yaml.rb oxidized@r61 -c "no cli session paging enable
show version
show inventory
enable
show running-config
exit" -o spec/model/data/mlnxos:Onyx_3.10.3004:simulation.yaml

robertcheramy avatar Apr 29 '25 05:04 robertcheramy

This issue is stale because it has been open 90 days with no activity.

github-actions[bot] avatar Jul 29 '25 02:07 github-actions[bot]