Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

libssh2_session_handshake() hangs #1369

Open
victorstewart opened this issue Apr 16, 2024 · 3 comments
Open

libssh2_session_handshake() hangs #1369

victorstewart opened this issue Apr 16, 2024 · 3 comments

Comments

@victorstewart
Copy link

victorstewart commented Apr 16, 2024 •
edited by vszakats

Describe the bug

even with libssh2_session_set_blocking(session, 0) set, libssh2_session_handshake often hangs for me... and then after a minute or more fails with LIBSSH2_ERROR_KEY_EXCHANGE_FAILURE. but the keys are correct and do work sometimes. they either work instantly or we hang for a while. so something is definitely wrong.

To Reproduce

this is the code i'm using.. nothing special...

bool connect(void)
{
   libssh2_session_set_blocking(session, 1);

   createTCPSocket(AF_INET);
   setIPv4FromString(host, 22);

   int rc = SocketBase::connect();

   if (rc != 0)
   {
      fprintf(stderr, "Failure establishing TCP connection: %d\n", rc);
      goto shutdown;
   }

   ipc_printf("SSHClient::connect: before calling libssh2_session_handshake\n");
   
   rc = libssh2_session_handshake(session, fd);

   if (rc != LIBSSH2_ERROR_NONE && rc != LIBSSH2_ERROR_EAGAIN) 
   {
      fprintf(stderr, "libssh2_session_handshake failed\n");
      printErrorString(rc);
      goto shutdown;
   }
   
   ipc_printf("SSHClient::connect: before calling libssh2_userauth_publickey_fromfile\n");


   rc = libssh2_userauth_publickey_fromfile(session, user.c_str(), pubkey_path.c_str(), privkey_path.c_str(), NULL);

   if (rc != LIBSSH2_ERROR_NONE && rc != LIBSSH2_ERROR_EAGAIN) 
   {
      fprintf(stderr, "libssh2_userauth_publickey_fromfile failed\n");
      printErrorString(rc);
      goto shutdown;
   }
   
   return true;

shutdown:

   ipc_printf("SSHClient::connect: checkpoint shutdown\n");
   
   if (session) 
   {
     libssh2_session_disconnect(session, "Normal Shutdown");
     libssh2_session_free(session);
   }

   return false;
}

Expected behavior
expect it to quickly complete as it does sometimes

Version:

  • OS and version: Linux (Clear Linux 6.8.4-1422)
  • libssh2 version: 1.11.0
  • crypto backend and version: OpenSSL 3

Additional context
@vszakats vszakats changed the title libssh2_session_handshake hangs libssh2_session_handshake() hangs Apr 16, 2024
@vszakats vszakats changed the title libssh2_session_handshake() hangs libssh2_session_handshake() hangs Apr 16, 2024
@victorstewart
Copy link
Author

victorstewart commented Apr 19, 2024 •
edited

here's some log with all debug besides LIBSSH2_TRACE_TRANS enabled, plus the packets filtered by the IP address of the target SSH server printed in order from custom eBPF observer programs i injected into the ingress and egress points of the ethernet device.

SSHClient::connect: before calling libssh2_session_handshake
[libssh2] 0.490676 Socket: Sent 24/24 bytes at 0x564548ab0085+0
[libssh2] 0.570576 Socket: Recved 1 bytes banner
[libssh2] 0.570583 Socket: Recved 1 bytes banner
[libssh2] 0.570585 Socket: Recved 1 bytes banner
[libssh2] 0.570586 Socket: Recved 1 bytes banner
[libssh2] 0.570587 Socket: Recved 1 bytes banner
[libssh2] 0.570588 Socket: Recved 1 bytes banner
[libssh2] 0.570589 Socket: Recved 1 bytes banner
[libssh2] 0.570590 Socket: Recved 1 bytes banner
[libssh2] 0.570591 Socket: Recved 1 bytes banner
[libssh2] 0.570592 Socket: Recved 1 bytes banner
[libssh2] 0.570593 Socket: Recved 1 bytes banner
[libssh2] 0.570594 Socket: Recved 1 bytes banner
[libssh2] 0.570595 Socket: Recved 1 bytes banner
[libssh2] 0.570596 Socket: Recved 1 bytes banner
[libssh2] 0.570597 Socket: Recved 1 bytes banner
[libssh2] 0.570598 Socket: Recved 1 bytes banner
[libssh2] 0.570600 Socket: Recved 1 bytes banner
[libssh2] 0.570601 Socket: Recved 1 bytes banner
[libssh2] 0.570602 Socket: Recved 1 bytes banner
[libssh2] 0.570603 Socket: Recved 1 bytes banner
[libssh2] 0.570604 Socket: Recved 1 bytes banner
[libssh2] 0.570605 Socket: Recved 1 bytes banner
[libssh2] 0.570606 Socket: Recved 1 bytes banner
[libssh2] 0.570607 Socket: Recved 1 bytes banner
[libssh2] 0.570608 Socket: Recved 1 bytes banner
[libssh2] 0.570609 Socket: Recved 1 bytes banner
[libssh2] 0.570610 Socket: Recved 1 bytes banner
[libssh2] 0.570611 Socket: Recved 1 bytes banner
[libssh2] 0.570612 Socket: Recved 1 bytes banner
[libssh2] 0.570614 Socket: Recved 1 bytes banner
[libssh2] 0.570616 Socket: Recved 1 bytes banner
[libssh2] 0.570618 Socket: Recved 1 bytes banner
[libssh2] 0.570633 Socket: Recved 1 bytes banner
[libssh2] 0.570635 Socket: Recved 1 bytes banner
[libssh2] 0.570637 Socket: Recved 1 bytes banner
[libssh2] 0.570639 Socket: Recved 1 bytes banner
[libssh2] 0.570662 Socket: Recved 1 bytes banner
[libssh2] 0.570665 Socket: Recved 1 bytes banner
[libssh2] 0.570667 Socket: Recved 1 bytes banner
[libssh2] 0.570703 Key Ex: Sent KEX: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1,diffie-hellman-group-exchange-sha1,ext-info-c
[libssh2] 0.570724 Key Ex: Sent HOSTKEY: ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ssh-ed25519,ssh-ed25519-cert-v01@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ssh-rsa-cert-v01@openssh.com,ssh-dss
[libssh2] 0.570729 Key Ex: Sent CRYPT_CS: aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc
[libssh2] 0.570732 Key Ex: Sent CRYPT_SC: aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc
[libssh2] 0.570735 Key Ex: Sent MAC_CS: hmac-sha2-256,hmac-sha2-256-etm@openssh.com,hmac-sha2-512,hmac-sha2-512-etm@openssh.com,hmac-sha1,hmac-sha1-etm@openssh.com,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com
[libssh2] 0.570739 Key Ex: Sent MAC_SC: hmac-sha2-256,hmac-sha2-256-etm@openssh.com,hmac-sha2-512,hmac-sha2-512-etm@openssh.com,hmac-sha1,hmac-sha1-etm@openssh.com,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com
[libssh2] 0.570761 Key Ex: Sent COMP_CS: none
[libssh2] 0.570763 Key Ex: Sent COMP_SC: none
[libssh2] 0.570764 Key Ex: Sent LANG_CS: 
[libssh2] 0.570766 Key Ex: Sent LANG_SC: 
[libssh2] 0.570821 Socket: Sent 1496/1496 bytes at 0x56454959b618
[libssh2] 0.664437 Socket: Recved 1120/35000 bytes to 0x564549592d20+0
[libssh2] 0.664454 Key Ex: Agreed on KEX method: curve25519-sha256
[libssh2] 0.664456 Key Ex: Agreed on HOSTKEY method: ecdsa-sha2-nistp256
[libssh2] 0.664457 Key Ex: Agreed on CRYPT_CS method: aes256-gcm@openssh.com
[libssh2] 0.664459 Key Ex: Agreed on CRYPT_SC method: aes256-gcm@openssh.com
[libssh2] 0.664461 Key Ex: Agreed on MAC_CS method: INTEGRATED-AES-GCM
[libssh2] 0.664463 Key Ex: Agreed on MAC_SC method: INTEGRATED-AES-GCM
[libssh2] 0.664464 Key Ex: Agreed on COMP_CS method: none
[libssh2] 0.664466 Key Ex: Agreed on COMP_SC method: none
[libssh2] 0.664597 Key Ex: Initiating curve25519 SHA2
[libssh2] 0.664622 Socket: Sent 48/48 bytes at 0x56454959b618
[libssh2] 120.321525 Socket: Error recving 35000 bytes (got 0)
[libssh2] 120.321534 Failure Event: -43 - Timeout waiting for ECDH_REPLY reply
[libssh2] 120.321541 Failure Event: -8 - Unrecoverable error exchanging keys
[libssh2] 120.321542 Failure Event: -8 - Unable to exchange encryption keys
libssh2_session_handshake failed
LIBSSH2_ERROR_KEY_EXCHANGE_FAILURE
SSHClient::connect: checkpoint shutdown
ingress
	nPackets = 256

	index = 9
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 38:94:ed:29:3e:7f
		dest -> 00:1f:c6:9c:37:2a
	ip
		src -> 93:4b:51:cf
		dest -> 0a:00:00:15
	tcp
		seq = 2158564377
		ack_seq = 2942865243
		sport = 22
		dport = 46694
		window = 85
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 13056

	index = 12
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 38:94:ed:29:3e:7f
		dest -> 00:1f:c6:9c:37:2a
	ip
		src -> 93:4b:51:cf
		dest -> 0a:00:00:15
	tcp
		seq = 2812875801
		ack_seq = 3345518427
		sport = 22
		dport = 46694
		window = 85
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 20
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 38:94:ed:29:3e:7f
		dest -> 00:1f:c6:9c:37:2a
	ip
		src -> 93:4b:51:cf
		dest -> 0a:00:00:15
	tcp
		seq = 2812875801
		ack_seq = 3345518427
		sport = 22
		dport = 46694
		window = 85
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 27652

	index = 21
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 38:94:ed:29:3e:7f
		dest -> 00:1f:c6:9c:37:2a
	ip
		src -> 93:4b:51:cf
		dest -> 0a:00:00:15
	tcp
		seq = 128848921
		ack_seq = 3345518427
		sport = 22
		dport = 46694
		window = 85
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 6144

	index = 32
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 38:94:ed:29:3e:7f
		dest -> 00:1f:c6:9c:37:2a
	ip
		src -> 93:4b:51:cf
		dest -> 0a:00:00:15
	tcp
		seq = 128848921
		ack_seq = 3345518427
		sport = 22
		dport = 46694
		window = 85
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 6144
egress
	nPackets = 111

	index = 0
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 2942865243
		ack_seq = 2158564377
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 5
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 2812875801
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 9
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 2812875801
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 17
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 2674823003
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 20
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 38
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 57
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 58
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 59
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 62
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 65
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 72
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072

	index = 86
	nFrames = 3
	redirectIfIdx = 0
	container_id -> 00:00:00:00
	eth
		src -> 00:1f:c6:9c:37:2a
		dest -> 38:94:ed:29:3e:7f
	ip
		src -> 0a:00:00:15
		dest -> 93:4b:51:cf
	tcp
		seq = 3345518427
		ack_seq = 128848921
		sport = 46694
		dport = 22
		window = 63
		syn = false
		ack = true
		fin = false
		rst = false
		payload_len = 3072
[libssh2] 120.330824 Socket: Sent 40/40 bytes at 0x5646ff842618

@victorstewart victorstewart mentioned this issue Apr 19, 2024
Open
@victorstewart
Copy link
Author

i tired downgrading to 1.10.0 and this error never appears, but now i have different errors with libssh2_sftp_write that i didn't see in 1.11.0 so i assume they're fixed. so kind of trapped here.

@victorstewart
Copy link
Author

if i keep just SIGINT-ing the program when it blocks on this error, then restart it, eventually it runs to completion.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@victorstewart