Login Failed, then Login Success syslog messages when logging in

[Paul Stafford]

I get the following syslog messages every time I login to my devices:

*Aug 21 09:46:18: %SEC_LOGIN-4-LOGIN_FAILED: Login failed [user: TEST] [Source: 10.0.0.1] [localport: 22] [Reason: Login Authentication Failed] at 09:46:18 CDT Wed Aug 21 2024
*Aug 21 09:46:20: %SEC_LOGIN-5-LOGIN_SUCCESS: Login Success [user: TEST] [Source: 10.0.0.1] [localport: 22] at 09:46:20 CDT Wed Aug 21 2024

Any idea why? 
I am able to login without any issues, it is just that I keep getting these "LOGIN FAILED" messages for no apparent reason.  

Thanks in advance,
Paul

[MHM Cisco World]

Do you use group of server for authc?

MHM

[Paul Stafford]

Normally I am using a tacacs server, but I notice even with just removing aaa altogether and using local user and local authentication, I still get this error.

Here is kind of the block diagram of my current test config on this device:

username TEST password abcd1234

line vty 0 15
login local

Thanks,
Paul

[MHM Cisco World]

Do 

Clear vty lines all

Then check log again 

MHM

[Paul Stafford]

No such command.  

I can clear line vty X, but there are no other sessions in use.

Thanks,
Paul

[MHM Cisco World]

After clear vty

try access and check log

And to confirm you don't use any aaa server for auth

MHM

[Paul Stafford]

No VTY in use, (except for the one I am logged in as), I have "no aaa new-model" in there, so no aaa server.  Same log messages... a failed login, then a successful login..... within a couple microseconds of each other as shown in the log above.

Thanks,
Paul

[Richard Burts]

Paul

That is odd. Am I correct in understanding that you are using SSH to access the devices? I wonder if there might be some version 1/version 2 of SSH involved? Would you post the output of show ip ssh?

Could you access the device, do terminal monitor, run debug for SSH,  access the device from another device, and see what other log messages are generated?

[Paul Stafford]

I think you are onto something.  I am logging into these devices with Linux and when I use another Linux box, I don't get the "login failed" messages.  

Here is the debug when I ssh from the Linux machine that causes login failures:

Aug 24 19:24:13.236: SSH2 2: send:packet of length 192 (length also includes padlen of 13)
Aug 24 19:24:13.236: SSH2 2: computed MAC for sequence no.#747 type 94
Aug 24 19:24:15.236: SSH2 2: send:packet of length 192 (length also includes padlen of 13)
Aug 24 19:24:15.236: SSH2 2: computed MAC for sequence no.#748 type 94
Aug 24 19:24:15.891: SSH1: starting SSH control process
Aug 24 19:24:15.891: SSH1: sent protocol version id SSH-2.0-Cisco-1.25
Aug 24 19:24:15.941: SSH1: protocol version id is - SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.9
Aug 24 19:24:15.941: SSH2 1: kexinit sent: kex algo = diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1
Aug 24 19:24:15.941: SSH2 1: Server certificate trustpoint not found. Skipping hostkey algo = x509v3-ssh-rsa
Aug 24 19:24:15.941: SSH2 1: kexinit sent: hostkey algo = ssh-rsa
Aug 24 19:24:15.941: SSH2 1: kexinit sent: encryption algo = aes128-ctr,aes192-ctr,aes256-ctr
Aug 24 19:24:15.941: SSH2 1: kexinit sent: mac algo = hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-sha1-96
Aug 24 19:24:15.941: SSH2 1: send:packet of length 312 (length also includes padlen of 4)
Aug 24 19:24:15.941: SSH2 1: SSH2_MSG_KEXINIT sent
Aug 24 19:24:15.941: SSH2 1: ssh_receive: 536 bytes received
Aug 24 19:24:15.941: SSH2 1: input: total packet length of 1344 bytes
Aug 24 19:24:15.941: SSH2 1: partial packet length(block size)8 bytes,needed 1336 bytes,
maclen 0
Aug 24 19:24:15.943: SSH2 1: ssh_receive: 536 bytes received
Aug 24 19:24:15.943: SSH2 1: partial packet length(block size)8 bytes,needed 1336 bytes,
maclen 0
Aug 24 19:24:15.943: SSH2 1: ssh_receive: 272 bytes received
Aug 24 19:24:15.943: SSH2 1: partial packet length(block size)8 bytes,needed 1336 bytes,
maclen 0
Aug 24 19:24:15.943: SSH2 1: input: padlength 7 bytes
Aug 24 19:24:15.943: SSH2 1: SSH2_MSG_KEXINIT received
Aug 24 19:24:15.943: SSH2 1: kex: client->server enc:aes128-ctr mac:hmac-sha2-256
Aug 24 19:24:15.943: SSH2 1: kex: server->client enc:aes128-ctr mac:hmac-sha2-256
Aug 24 19:24:15.943: SSH2 1: Using kex_algo = diffie-hellman-group14-sha1
Aug 24 19:24:16.007: SSH2 1: expecting SSH2_MSG_KEXDH_INIT
Aug 24 19:24:16.179: SSH2 1: ssh_receive: 272 bytes received
Aug 24 19:24:16.179: SSH2 1: input: total packet length of 272 bytes
Aug 24 19:24:16.179: SSH2 1: partial packet length(block size)8 bytes,needed 264 bytes,
maclen 0
Aug 24 19:24:16.181: SSH2 1: input: padlength 6 bytes
Aug 24 19:24:16.181: SSH2 1: SSH2_MSG_KEXDH_INIT received
Aug 24 19:24:16.259: SSH2 2: send:packet of length 2016 (length also includes padlen of 16)
Aug 24 19:24:16.259: SSH2 2: computed MAC for sequence no.#749 type 94
Aug 24 19:24:16.339: SSH2 1: signature length 271
Aug 24 19:24:16.339: SSH2 1: send:packet of length 832 (length also includes padlen of
Aug 24 19:24:16.339: SSH2: kex_derive_keys complete
Aug 24 19:24:16.339: SSH2 1: send:packet of length 16 (length also includes padlen of 10)
Aug 24 19:24:16.339: SSH2 1: newkeys: mode 1
Aug 24 19:24:16.339: SSH1: TCP send failed enqueueing
Aug 24 19:24:16.377: SSH2 1: SSH2_MSG_NEWKEYS sent
Aug 24 19:24:16.377: SSH2 1: waiting for SSH2_MSG_NEWKEYS
Aug 24 19:24:16.381: SSH2 1: ssh_receive: 16 bytes received
Aug 24 19:24:16.381: SSH2 1: input: total packet length of 16 bytes
Aug 24 19:24:16.381: SSH2 1: partial packet length(block size)8 bytes,needed 8 bytes,
maclen 0
Aug 24 19:24:16.381: SSH2 1: input: padlength 10 bytes
Aug 24 19:24:16.381: SSH2 1: newkeys: mode 0
Aug 24 19:24:16.381: SSH2 1: SSH2_MSG_NEWKEYS received
Aug 24 19:24:16.623: SSH2 1: ssh_receive: 64 bytes received
Aug 24 19:24:16.623: SSH2 1: input: total packet length of 32 bytes
Aug 24 19:24:16.623: SSH2 1: partial packet length(block size)16 bytes,needed 16 bytes,
maclen 32
Aug 24 19:24:16.623: SSH2 1: MAC compared for #3 :ok
Aug 24 19:24:16.623: SSH2 1: input: padlength 10 bytes
Aug 24 19:24:16.623: SSH2 1: send:packet of length 32 (length also includes padlen of 10)
Aug 24 19:24:16.623: SSH2 1: computed MAC for sequence no.#3 type 6
Aug 24 19:24:16.623: SSH2 1: send:packet of length 1232 (length also includes padlen of 11)
Aug 24 19:24:16.623: SSH2 1: computed MAC for sequence no.#4 type 53
Aug 24 19:24:16.623: SSH2 1: Authentications that can continue = publickey,keyboard-interactive,password
Aug 24 19:24:16.671: SSH2 1: ssh_receive: 80 bytes received
Aug 24 19:24:16.671: SSH2 1: input: total packet length of 48 bytes
Aug 24 19:24:16.671: SSH2 1: partial packet length(block size)16 bytes,needed 32 bytes,
maclen 32
Aug 24 19:24:16.671: SSH2 1: MAC compared for #4 :ok
Aug 24 19:24:16.671: SSH2 1: input: padlength 8 bytes
Aug 24 19:24:16.671: SSH2 1: Using method = none
Aug 24 19:24:16.671: SSH2 1: Authentications that can continue = publickey,keyboard-interactive,password
Aug 24 19:24:16.671: SSH2 1: send:packet of length 64 (length also includes padlen of 14)
Aug 24 19:24:16.671: SSH2 1: computed MAC for sequence no.#5 type 51
Aug 24 19:24:16.721: SSH2 1: ssh_receive: 512 bytes received
Aug 24 19:24:16.721: SSH2 1: input: total packet length of 480 bytes
Aug 24 19:24:16.721: SSH2 1: partial packet length(block size)16 bytes,needed 464 bytes,
maclen 32
Aug 24 19:24:16.721: SSH2 1: MAC compared for #5 :ok
Aug 24 19:24:16.721: SSH2 1: input: padlength 12 bytes
Aug 24 19:24:16.721: SSH2 1: Using method = publickey
Aug 24 19:24:16.721: SSH2 1: Received publickey algo = ssh-rsa
Aug 24 19:24:16.721: SSH2 1: Verifying pubkey blob is acceptable for 'TestUser' in SSH2_MSG_USERAUTH_REQUEST
Aug 24 19:24:16.721: SSH2 1: Publickey for 'TestUser' not found
Aug 24 19:24:16.721: SSH2 1: Pubkey Authentication failed for user 'TestUser'
Aug 24 19:24:16.721: SSH1: password authentication failed for TestUser
Aug 24 19:24:17.271: SSH2 2: send:packet of length 3392 (length also includes padlen of 16)
Aug 24 19:24:17.271: SSH2 2: computed MAC for sequence no.#750 type 94
Aug 24 19:24:18.273: SSH2 2: send:packet of length 560 (length also includes padlen of 6)
Aug 24 19:24:18.273: SSH2 2: computed MAC for sequence no.#751 type 94
Aug 24 14:24:18: %SEC_LOGIN-4-LOGIN_FAILED: Login failed [user: TestUser] [Source: 10.0.0.1] [localport: 22] [Reason: Login Authentication Failed] at 14:24:18 CDT Sat Aug 24 2024
Aug 24 19:24:18.721: SSH2 1: Authentications that can continue = publickey,keyboard-interactive,password
Aug 24 19:24:18.721: SSH2 1: send:packet of length 64 (length also includes padlen of 14)
Aug 24 19:24:18.721: SSH2 1: computed MAC for sequence no.#6 type 51
Aug 24 19:24:18.931: SSH2 1: ssh_receive: 112 bytes received
Aug 24 19:24:18.931: SSH2 1: input: total packet length of 80 bytes
Aug 24 19:24:18.931: SSH2 1: partial packet length(block size)16 bytes,needed 64 bytes,
maclen 32
Aug 24 19:24:18.931: SSH2 1: MAC compared for #6 :ok
Aug 24 19:24:18.931: SSH2 1: input: padlength 16 bytes
Aug 24 19:24:18.931: SSH2 1: Using method = keyboard-interactive
Aug 24 19:24:19.009: SSH2 1: send:packet of length 48 (length also includes padlen of 11)
Aug 24 19:24:19.009: SSH2 1: computed MAC for sequence no.#7 type 60
Aug 24 19:24:19.273: SSH2 2: send:packet of length 1056 (length also includes padlen of 7)
Aug 24 19:24:19.273: SSH2 2: computed MAC for sequence no.#752 type 94
Aug 24 19:24:20.274: SSH2 2: send:packet of length 352 (length also includes padlen of 11)
Aug 24 19:24:20.274: SSH2 2: computed MAC for sequence no.#753 type 94
Aug 24 19:24:20.470: SSH2 1: ssh_receive: 96 bytes received
Aug 24 19:24:20.470: SSH2 1: input: total packet length of 64 bytes
Aug 24 19:24:20.470: SSH2 1: partial packet length(block size)16 bytes,needed 48 bytes,
maclen 32
Aug 24 19:24:20.470: SSH2 1: MAC compared for #7 :ok
Aug 24 19:24:20.470: SSH2 1: input: padlength 44 bytes
Aug 24 19:24:20.520: SSH2 1: send:packet of length 16 (length also includes padlen of 10)
Aug 24 19:24:20.520: SSH2 1: computed MAC for sequence no.#8 type 52
Aug 24 19:24:20.520: SSH2 1: authentication successful for TestUser
Aug 24 14:24:20: %SEC_LOGIN-5-LOGIN_SUCCESS: Login Success [user: TestUser] [Source: 10.0.0.1] [localport: 22] at 14:24:20 CDT Sat Aug 24 2024
Aug 24 19:24:20.564: SSH2 1: ssh_receive: 80 bytes received
Aug 24 19:24:20.564: SSH2 1: input: total packet length of 48 bytes
Aug 24 19:24:20.564: SSH2 1: partial packet length(block size)16 bytes,needed 32 bytes,
maclen 32

[Richard Burts]

Thanks for the debug output. While I look into it I have a couple of things:

- Pretty clearly the behaviors reflect differences in client used to access your Cisco. Some clients login with no failure while other clients login experience a failure and then success. Any insight into the clients being used?

- I suspect that at least part of the issue is which version of SSH is being used. Would you post the output show ip ssh

[Richard Burts]

I find in the debug output that there was an attempt to use SSH1 which failed:

Aug 24 19:24:16.339: SSH1: TCP send failed enqueueing

Aug 24 19:24:16.721: SSH1: password authentication failed for TestUser

And then authentication using SSH2 is successful

Aug 24 19:24:20.520: SSH2 1: authentication successful for TestUser

The time difference is similar to the times of the log messages in the OP.

As stated in my previous post the issue here seems to be differences in client behavior (does it use just one version for SSH or to use both). If it is consistent that SSH2 works and SSH1 does not then perhaps you might want to specify in the Cisco configs to use only SSH2.  Or perhaps if it is clear that it is about client behaviors you might want to just leave the Cisco config as it is.

[Paul Stafford · Accepted solution]

I figured it out... I deleted the id_rsa and id_rsa.pub off of the linux box that was giving me the issues and I no longer get the failed messages.  Thanks for your help!

Paul

[Richard Burts]

Paul

Thanks for the update. Glad that you have solved the issue. Thanks for sharing the solution.