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.

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

Bug: Connecting through SSH Tunnel Using Plink within Windows 10 64bit isn't established #521

Closed
Reiner030 opened this Issue Jan 30, 2019 · 14 comments

Comments

Projects
None yet
3 participants
@Reiner030
Copy link

Reiner030 commented Jan 30, 2019

Opening issue as in https://www.heidisql.com/forum.php?t=26506#p26509 requestd.

I have this bug (like www.heidisql.com/forum.php?t=15224 one years ago) since latest 9.5 up to actual 10.1.0.5471 version since I was switched from Windows 7 64bit to Windows 10 64bit version in November.

In first tries it seems to be related to 64bit version of HeidiSQL because last year I got running the 9.5 portable 32bit version but thats now also not working anymore.

The connection to SSH server is established and request for my SSH pubkey by agent is made and accepted but then HeidiSQL is hanging endless without connecting successful through the tunnel to the MariaDB servers.

Both 32/64 bit versions are connecting fine to MariaDB servers (running different versions 10.1 / 10.2).

  • plink itself is working fine and I can "reuse" the already opened tunnel by connecting to localhost port 3307 (default port setup by config).

  • using "Confirm key usage" on putty agent or not makes no difference - Idea was that here timeout could be reached while waiting for allowing the key sending.

  • Using a different port or a different plink timeout than 4 makes no difference to this problem.

  • When doing a "taskkill.exe /F /IM plink.exe" HeidiSQL recognizes the disconnect and gets out immediately the error message: "Lost connection to MySQL server at 'reading authorization packet', system error: 0"
    If there is a chance to help you to debug the call/error I can try to get some diagnose logs for you.

There seems yet no "actual" bug notification by someone other on this cause so I opened a new one.

Steps to reproduce this issue

  1. Setup a connection with "MariaDB or MySQL (SSH tunnel)"
  2. Have a ssh remote endpoint using ssh pubkey authorization.
  3. Optional using putty agent (or gpg-agent)
  4. Start connection

Current behavior

HeidiSQL freezes / waits endless for MariaDB/MySQL connection

  • Using PuTTY Agent:

    • plink.exe is running fine and is connected to remote server.
      But connect to MariaDB/MySQL is not established by HeidiSQL

    • if plink.exe is terminated HeidiSQL unfreezes and throws the error:
      Lost connection to MySQL server at 'reading authorization packet

    • Changing timout time gave no changes in behavior.

  • Using GPG Agent:

    • With gpg-agent for pubkey authorization I got the error
      Can't connect to MySQL server on '127.0.0.1' (10061) and afterwards HeidiSQL freezes.
    • Changing timout time gave no changes in behavior.
  • With direct password type-in:

    • I got the plink pop question for entering the pubkey password.
      After it was typed in I got the error Can't connect to MySQL server on '127.0.0.1' (10061) and HeidiSQL is not freezed.
    • There is no plink.exe running / to be terminated.
    • Changing timout time gave no changes in behavior.

Expected behavior

Should connect to MariaDB/MySQL server as in direct links.

Possible solution

Environment

  • HeidiSQL version:
    From HeidiSQL 9.5.x till latest nightly version 10.1.x
  • Database system and version:
    Tested with MariaDB 10.1.31 and MariaDB 10.2.14 / 10.2.22
    Not related to this bug because direct TCP/IP connections are possible.
  • Operating system:
    Latest Windows 10 Professional Nov. 2018 till now

@ansgarbecker ansgarbecker added the mysql label Jan 31, 2019

@petertiny

This comment has been minimized.

Copy link

petertiny commented Feb 12, 2019

Hello Guys,
I love HeidiSQL for many years and use it every day !
But I have the same problem and it's very annoying because I can't join my new mysql servers.
Please do something Ansgar :)
And thanks a lot for all your work
Au revoir
Pierre

@ansgarbecker

This comment has been minimized.

Copy link
Collaborator

ansgarbecker commented Feb 12, 2019

Please try to connect via HeidiSQL to 127.0.0.1 after creating a tunnel by yourself using plink.exe. If that works like you expect, then we should be able to see the cause why it isn't working in Heidi.

@Reiner030

This comment has been minimized.

Copy link
Author

Reiner030 commented Feb 12, 2019

Hello @ansgarbecker ,

If this question was on me: I had successful tested manual call of plink like

"C:\Program Files\PuTTY\plink.exe" <mysql-host> -l <my-account> -s -N -L 127.0.0.1:3307:localhost:3306

because I didn't see/debug how HeidiSQL is calling this program.
But it also works fine as written with an additional HeidiSQL connect on localhost:3307

Or do you asked this to @petertiny ?

@Reiner030

This comment has been minimized.

Copy link
Author

Reiner030 commented Apr 12, 2019

Hello @ansgarbecker ,

I found the cause in latest 10.1 version by activating SQL logging to file which also writes the plink call/output as SQL comments into it.

You are calling plink.exe with the wrong -ssh parameter:

C:\Program Files\PuTTY\plink.exe -ssh <user>@<host> -P 22 -N -L 3308:localhost:3306 */

which creates an unneeded interactive shell and causes an interactive prompt which must be accepted before having ports forwarded:

...
Pageant is running. Requesting keys.
Pageant has 1 SSH-2 keys
Using username "reiner.keller".
Trying Pageant key #0
Authenticating with public key "Reiner Keller - RSA" from agent
Sending Pageant's response
Access granted
Access granted. Press Return to begin session.
Local port 3307 forwarding to localhost:3306
^C

You need to switch the parameter to --batch to use the non-interactive mode.

Pageant is running. Requesting keys.
Pageant has 1 SSH-2 keys
Using username "reiner.keller".
Trying Pageant key #0
Authenticating with public key "Reiner Keller - RSA" from agent
Sending Pageant's response
Access granted
Local port 3307 forwarding to localhost:3306
Opening connection to localhost:3306 for forwarding from 127.0.0.1:60100
Forwarded port closed
^C
@petertiny

This comment has been minimized.

Copy link

petertiny commented Apr 12, 2019

Great !!
How can i configure that ? Or do i wait for a new release ?
Thanks

@Reiner030

This comment has been minimized.

Copy link
Author

Reiner030 commented Apr 12, 2019

I think we have to wait for a nightly release with this fix because the plink call is not configurable but compiled in. But I guess this won't take long to get it active since there was already a response by developer ;)

After cloning/checking for the line with wrong create online the fix/pull request; Github fixed nearby mixed newline to Windows ones:
#610

ansgarbecker added a commit that referenced this issue Apr 13, 2019

Issue #521: use -batch instead of -ssh parameter for plink, to preven…
…t creating a shell and to reduce interactive prompts
@ansgarbecker

This comment has been minimized.

Copy link
Collaborator

ansgarbecker commented Apr 13, 2019

Thanks for that pull request. As I am a bit picky about unrelated changes in commits, I did not merge the pull request with the unintentionally line feed changes. Also I don't know how to merge only a part of a pull request.

Are you sure that -batch parameter works with older plink versions?

@Reiner030

This comment has been minimized.

Copy link
Author

Reiner030 commented Apr 13, 2019

Hi, no problem - the line switch was automatically done by Github when doing online edit.

The batch parameter exists since beginning as e.g. here shown:
https://www.axel-hahn.de/batch/helferlein-und-tabellen/andere-kommandos?id=plink

PuTTY Link: command-line connection utility
Development snapshot 2003-05-29
Usage: plink [options] [user@]host [command]
       ("host" can also be a PuTTY saved session name)
Options:
  -v        show verbose messages
  -load sessname  Load settings from saved session
  -ssh -telnet -rlogin -raw
            force use of a particular protocol (default SSH)
  -P port   connect to specified port
  -l user   connect with specified username
  -m file   read remote command(s) from file
  -batch    disable all interactive prompts
...

EDIT: If not yet patched; you can also add instead switching the parameter -ssh which is default connection type so it's not needed but if you want to be sure (as before) you can use both parameters:

C:\Program Files\PuTTY\plink.exe -ssh -batch <user>@<host> -P 22 -N -L 3308:localhost:3306
...
Pageant is running. Requesting keys.
Pageant has 4 SSH-2 keys
Using username "reiner.keller".
Trying Pageant key #0
Authenticating with public key "Reiner Keller - RSA" from agent
Sending Pageant's response
Access granted
Local port 3308 forwarding to localhost:3306
@Reiner030

This comment has been minimized.

Copy link
Author

Reiner030 commented Apr 13, 2019

Hi @ansgarbecker, sadly this seems not fix the problem yet.

Is it possible to get enhanced logging active for nightly builds to better see what the problem is? Perhaps this could also be later default if it make sense or a checkbox option.

diff --git a/source/dbconnection.pas b/source/dbconnection.pas
index 44fea19b..8db9f19b 100644
--- a/source/dbconnection.pas
+++ b/source/dbconnection.pas
@@ -870,7 +870,7 @@ begin

   // Build plink.exe command line
   // plink bob@domain.com -pw myPassw0rd1 -P 22 -i "keyfile.pem" -L 55555:localhost:3306
-  PlinkCmd := FConnection.Parameters.SSHPlinkExe + ' -batch ';
+  PlinkCmd := FConnection.Parameters.SSHPlinkExe + ' -ssh -batch -v ';
   if FConnection.Parameters.SSHUser <> '' then
     PlinkCmd := PlinkCmd + FConnection.Parameters.SSHUser + '@';
   if FConnection.Parameters.SSHHost <> '' then

And I am a little wondering why the path is now shown wrong - instead of \ I see there a striked-through W:
heidisql-plink exe-weird-path

but it seems correct from logging:

/* Connecting to localhost via MariaDB (SSH tunnel), username root, using password: Yes ... */
/* Attempt to create plink.exe process, waiting 4s for response ... */
/* C:\Program Files\PuTTY\plink.exe -batch reiner.keller@<host> -P 22 -N -L 3307:localhost:3306 */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText:Using username "reiner.keller".
 */
/* PLink: Using username "reiner.keller".
 */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* Ping server ... */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* Bad handshake */
/* Closing plink.exe process #308392 ... */

Compared to direct cmd call:

C:\Users\reiner.keller>"C:\Program Files\PuTTY\plink.exe" -batch reiner.keller@<host> -P 22 -N -L 3307:localhost:3306
Using username "reiner.keller".

I am only a little wondering where the 4 additional empty ErrorText lines come from.

@ansgarbecker

This comment has been minimized.

Copy link
Collaborator

ansgarbecker commented Apr 14, 2019

  • just added -ssh and -v arguments back to the command. Though I'm unsure why that -ssh is important as it's the default anyway, according to the documentation
  • The empty "ErrorText:" log lines can be ignored - these come in due to an interval based query of the output pipes
@Reiner030

This comment has been minimized.

Copy link
Author

Reiner030 commented Apr 14, 2019

Hi @ansgarbecker,

thanks for updating the call for testing.
Seems that it's better to revert it for next nightly builds again.

The behavior is weird, now I got a popup exception window for the first three lines:

Looking up host "<host>" for SSH connection
Connecting to <ip> port 22
We claim version: SSH-2.0-PuTTY_Release_0.71

and in log I have these lines:

/* Attempt to create plink.exe process, waiting 4s for response ... */
/* C:\Program Files\PuTTY\plink.exe -ssh -batch -v reiner.keller@<host> -P 22 -N -L 3307:localhost:3306 */
/* plink OutText: ErrorText:Looking up host "<host>" for SSH connection
Connecting to <ip> port 22
We claim version: SSH-2.0-PuTTY_Release_0.71
 */
/* Ping server ... */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* Can't connect to MySQL server on '127.0.0.1' (10061) */
/* Closing plink.exe process #410348 ... */

For this host it seems to be also a problem that IPv6 access is tried too long before switching to IPv4 connection.
Increasing the plink timeout from 4s to e.g. 30s or 60s didn't change the behavior - HeidiSQL ist still waiting only 4s/showing the 4 empty plink OutText lines and stop/close after 4s the plink process.

=> Could there be a problem with these lines which breaks somehow the waiting loop?

    // Exit loop after 1s idletime when there was output earlier
    if (ReturnedSomethingAt > 0) and (Waited >= ReturnedSomethingAt+1000) then
      Break;

So I tried another host with IPv4 only and get here 2 popups.
Again the first 3 lines as on other host ast first popup and after it the other lines beginning with Doing ECDH key exchange ... plink output which might be cause by waiting for opening connection build up:

/* Connecting to <rds-host> via MariaDB or MySQL (SSH tunnel), username master, using password: Yes ... */
/* Attempt to create plink.exe process, waiting 4s for response ... */
/* C:\Program Files\PuTTY\plink.exe -ssh -batch -v reiner.keller@<host2> -P 22 -N -L 3307:<rds-host>:3306 */
/* plink OutText: ErrorText:Looking up host "<host2>" for SSH connection
Connecting to <ip2> port 22
We claim version: SSH-2.0-PuTTY_Release_0.71
 */
/* plink OutText: ErrorText:Remote version: SSH-2.0-OpenSSH_7.4p1 Debian-10+deb9u6
Using SSH protocol version 2
No GSSAPI security context available
Doing ECDH key exchange with curve Curve25519 and hash SHA-256 (unaccelerated)
Server also has ssh-ed25519/ecdsa-sha2-nistp256 host keys, but we don't know any of them
Host key fingerprint is:
ssh-rsa 2048 c3:ef:df:74:f9:50:f2:a8:ea:22:6b:b7:2d:ad:87:31
Initialised AES-256 SDCTR (AES-NI accelerated) outbound encryption
Initialised HMAC-SHA-256 (unaccelerated) outbound MAC algorithm
Initialised AES-256 SDCTR (AES-NI accelerated) inbound encryption
Initialised HMAC-SHA-256 (unaccelerated) inbound MAC algorithm
Pageant is running. Requesting keys.
Pageant has 2 SSH-2 keys
Using username "reiner.keller".
Trying Pageant key #0
Server refused our key
Trying Pageant key #1
Authenticating with public key "Reiner Keller - RSA" from agent
Sending Pageant's response
Access granted
Local port 3307 forwarding to <rds-host>:3306
 */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* Lost connection to MySQL server at 'reading authorization packet', system error: 10061 */
/* Closing plink.exe process #409760 ... */

The lost connection comes from hard kill of pagent.exe after some minutes blocking HeidiSQL foreground process.

So the plink.exe process is running fine with -batch call but afterwards there are still problems:

  • when plink handshake takes longer it's ignored/tried too early
  • when plink handshake fits there is still something hanging in the MySQL/MariaDB handshake "forever".
    I tried it on both servers
    • with and without option compressed client/server protocol activated.
    • with actual and yesterday nightly build; both have same behavior

Since I didn't know howto debug such MySQL handshakes I sadly cannot help here much but it seems that the handshake is somehow not started correctly / too early to get the connection up and running.

ansgarbecker added a commit that referenced this issue Apr 15, 2019

@ansgarbecker

This comment has been minimized.

Copy link
Collaborator

ansgarbecker commented Apr 15, 2019

I just removed the -v argument for now, to see if that already does the job now. I personally don't get any dialogs now which were there before. Would be good to know if you keep getting one or more, with your probably special server :)

@Reiner030

This comment has been minimized.

Copy link
Author

Reiner030 commented Apr 15, 2019

Hi @ansgarbecker,

thanks and best is that other people like @petertiny could also test the new behavior.

I have no special server and tested it before with 2 and today with 3 different servers.

  • The ssh login servers are running Debian Stretch/9 with default sshd setup
    only with password authentication deactivated.
  • One instance is running in AWS with RDS MariaDB 10.1.x instance (as master)
  • Other server is running on external DC with latest MariaDB 10.2.x (as slave, MariaDB repository)
  • Today instance is running in office with latest MariaDB 10.2.x (as slave, MariaDB repository)

The only party why on external DC the IPv6 connection is delaying / not connecting comes because I use at home a HE IPv6 network tunnel with is geolocated in US and I allow SSH connects only from DE using converted MaxMind GeopIP2 database because last time the sshd scanner were very aggressive scanning even they have no chance to get in.

With todays nightly build I got now on all 3 connections

  • sometimes this popup window:
    Can't connect to MySQL server on '127.0.0.1' (10061)
  • most time this popup window:
    PLink exited unexpected. Command line was: C:\Program Files\PuTTY\plink.exe -ssh -batch reiner.keller@10.30.2.208 -P 22 -N -L 3307:localhost:3306
    (with different host names/forwarding hostnames on other 2 connections)
    Bad handshake

EDIT:
Sorry, the PLink exited unexpected. error came from switched pagent process which wasn't started right after reboot and popup wasn't popping up for my SSH key password input.
Now I have the Bad handshake error but the MariaDB servers are supported - after a manual plink call a connection to localhost:3307 works fine.

One idea came up - should the Using username "..." message be recognized and logged as ErrorText and as direct PLink: line ?

/* Connection to localhost closed at 2019-04-15 23:06:09 */
/* Connecting to localhost via MariaDB or MySQL (SSH tunnel), username root, using password: Yes ... */
/* Attempt to create plink.exe process, waiting 4s for response ... */
/* C:\Program Files\PuTTY\plink.exe -ssh -batch reiner.keller@10.30.2.208 -P 22 -N -L 3307:localhost:3306 */
/* plink OutText: ErrorText: */
/* Ping server ... */
/* plink OutText: ErrorText:Using username "reiner.keller".
 */
/* PLink: Using username "reiner.keller".
 */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* plink OutText: ErrorText: */
/* Bad handshake */
/* Closing plink.exe process #15140 ... */

because it's again remembering me onto this not clear break of the given timeout by configuration:

 // Exit loop after 1s idletime when there was output earlier
    if (ReturnedSomethingAt > 0) and (Waited >= ReturnedSomethingAt+1000) then
      Break;

The 4-5 /* plink OutText: ErrorText: */ lines looks fine so far but even if I extend timeout to e.g. 10s I still got only these 4-5 lines...

@ansgarbecker

This comment has been minimized.

Copy link
Collaborator

ansgarbecker commented Apr 16, 2019

I have just increased that waiter after PLink output from 1s to 2s, hoping this makes any difference for you. Also, the debug output lines should now only appear if there was any PLink output at all.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.