search

ropensci / ssh

Native SSH client in R based on libssh
https://docs.ropensci.org/ssh
Other
127 stars 21 forks source link

R 3.5.2 on Windows 10: fatal error during ssh_connect #24

Closed mathesong closed 5 years ago

mathesong commented 5 years ago
Session Info ```r - Session info ----------------------------------------------------------------------------------- setting value version R version 3.5.2 (2018-12-20) os Windows 10 x64 system x86_64, mingw32 ui RStudio language (EN) collate English_United Kingdom.1252 ctype English_United Kingdom.1252 tz Europe/Berlin date 2019-03-12 - Packages --------------------------------------------------------------------------------------- package * version date lib source analogsea * 0.6.6.9110 2019-03-12 [1] Github (sckott/analogsea@26f3574) assertthat 0.2.0 2017-04-11 [1] CRAN (R 3.5.2) aws.s3 0.3.12 2018-05-25 [1] CRAN (R 3.5.2) aws.signature 0.4.4 2018-07-27 [1] CRAN (R 3.5.2) backports 1.1.3 2018-12-14 [1] CRAN (R 3.5.2) base64enc 0.1-3 2015-07-28 [1] CRAN (R 3.5.2) callr 3.1.1 2018-12-21 [1] CRAN (R 3.5.2) cli 1.0.1 2018-09-25 [1] CRAN (R 3.5.2) colorspace 1.4-0 2019-01-13 [1] CRAN (R 3.5.2) crayon 1.3.4 2017-09-16 [1] CRAN (R 3.5.2) desc 1.2.0 2018-05-01 [1] CRAN (R 3.5.2) devtools 2.0.1 2018-10-26 [1] CRAN (R 3.5.2) digest 0.6.18 2018-10-10 [1] CRAN (R 3.5.2) dplyr 0.8.0.1 2019-02-15 [1] CRAN (R 3.5.2) fs 1.2.6 2018-08-23 [1] CRAN (R 3.5.2) ggplot2 * 3.1.0 2018-10-25 [1] CRAN (R 3.5.2) glue 1.3.0 2018-07-17 [1] CRAN (R 3.5.2) granviller * 0.0.0.9000 2019-03-02 [1] Github (mathesong/granviller@97673aa) gtable 0.2.0 2016-02-26 [1] CRAN (R 3.5.2) httr 1.4.0 2018-12-11 [1] CRAN (R 3.5.2) jsonlite 1.6 2018-12-07 [1] CRAN (R 3.5.2) lazyeval 0.2.1 2017-10-29 [1] CRAN (R 3.5.2) magrittr 1.5 2014-11-22 [1] CRAN (R 3.5.2) memoise 1.1.0 2017-04-21 [1] CRAN (R 3.5.2) munsell 0.5.0 2018-06-12 [1] CRAN (R 3.5.2) pillar 1.3.1 2018-12-15 [1] CRAN (R 3.5.2) pkgbuild 1.0.2 2018-10-16 [1] CRAN (R 3.5.2) pkgconfig 2.0.2 2018-08-16 [1] CRAN (R 3.5.2) pkgload 1.0.2 2018-10-29 [1] CRAN (R 3.5.2) plyr 1.8.4 2016-06-08 [1] CRAN (R 3.5.2) prettyunits 1.0.2 2015-07-13 [1] CRAN (R 3.5.2) processx 3.3.0 2019-03-10 [1] CRAN (R 3.5.3) ps 1.3.0 2018-12-21 [1] CRAN (R 3.5.2) purrr 0.3.1 2019-03-03 [1] CRAN (R 3.5.2) R6 2.4.0 2019-02-14 [1] CRAN (R 3.5.2) Rcpp 1.0.0 2018-11-07 [1] CRAN (R 3.5.2) remotes 2.0.2 2018-10-30 [1] CRAN (R 3.5.2) rlang 0.3.1 2019-01-08 [1] CRAN (R 3.5.2) rprojroot 1.3-2 2018-01-03 [1] CRAN (R 3.5.2) rstudioapi 0.9.0 2019-01-09 [1] CRAN (R 3.5.2) scales 1.0.0 2018-08-09 [1] CRAN (R 3.5.2) sessioninfo 1.1.1 2018-11-05 [1] CRAN (R 3.5.2) tibble 2.0.1 2019-01-12 [1] CRAN (R 3.5.2) tidyselect 0.2.5 2018-10-11 [1] CRAN (R 3.5.2) usethis 1.4.0 2018-08-14 [1] CRAN (R 3.5.2) withr 2.1.2 2018-03-15 [1] CRAN (R 3.5.2) xml2 1.2.0 2018-01-24 [1] CRAN (R 3.5.2) yaml 2.2.0 2018-07-25 [1] CRAN (R 3.5.2) [1] C:/Users/mathe/OneDrive/Documents/R/win-library/3.5 [2] C:/Program Files/R/R-3.5.2/library ```

This issue is the followup from https://github.com/sckott/analogsea/issues/173 , where I was having issues with setting up a DigitalOcean docklet. Upon further inspection, I identified that the issue occurs within the ssh::ssh_connect() function, and specifically at the following line:

 .Call(C_start_session, details$host, details$port, details$user, 
        keyfile, passwd, verbose)

I will therefore close the other issue (thanks for the help @sckott )

Using the following code, I consisitently experience R crashing out:

library(analogsea)

docklet_create(region="ams3", image="ubuntu-16-04-x64")

d <- droplets()[[1]]

docklet_rstudio(d, user="test", password="test123", verbose=TRUE)

From the suggestion of @jeroen , I ran debug(ssh::ssh_connect), and set verbose=4 (it doesn't seem to support 5), and got the following log

ssh_connect: libssh 0.8.6 (c) 2003-2018 Aris Adamantiadis, Andreas Schneider and libssh contributors. Distributed under the LGPL, please refer to COPYING file for information about your rights, using threading threads_pthread
getai: host 188.166.55.13 matches an IP address
ssh_socket_connect: Nonblocking connection socket: 1472
ssh_connect: Socket connecting, now waiting for the callbacks to work
ssh_connect: Actual timeout : 10000
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLOUT ), out buffer 0
ssh_socket_pollcallback: Received POLLOUT in connecting state
socket_callback_connected: Socket connection callback: 1 (0)
ssh_socket_unbuffered_write: Enabling POLLOUT for socket
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLOUT ), out buffer 0
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLIN ), out buffer 0
callback_receive_banner: Received banner: SSH-2.0-OpenSSH_7.2p2 Ubuntu-4ubuntu2.7
ssh_client_connection_callback: SSH server banner: SSH-2.0-OpenSSH_7.2p2 Ubuntu-4ubuntu2.7
ssh_analyze_banner: Analyzing banner: SSH-2.0-OpenSSH_7.2p2 Ubuntu-4ubuntu2.7
ssh_analyze_banner: We are talking to an OpenSSH client version: 7.2 (70200)
ssh_known_hosts_read_entries: Failed to open the known_hosts file '/etc/ssh/ssh_known_hosts': No such file or directory
ssh_client_select_hostkeys: Changing host key method to "ssh-ed25519,ssh-ed25519,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,ssh-rsa,ssh-dss"
ssh_list_kex: kex algos: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1,ext-info-c
ssh_list_kex: server host key algo: ssh-ed25519,ssh-ed25519,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,ssh-rsa,ssh-dss
ssh_list_kex: encryption client->server: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc
ssh_list_kex: encryption server->client: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc
ssh_list_kex: mac algo client->server: hmac-sha2-256,hmac-sha2-512,hmac-sha1
ssh_list_kex: mac algo server->client: hmac-sha2-256,hmac-sha2-512,hmac-sha1
ssh_list_kex: compression algo client->server: none
ssh_list_kex: compression algo server->client: none
ssh_list_kex: languages client->server: 
ssh_list_kex: languages server->client: 
ssh_socket_unbuffered_write: Enabling POLLOUT for socket
packet_send2: packet: wrote [len=652,padding=5,comp=646,payload=646]
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLIN POLLOUT ), out buffer 0
ssh_packet_socket_callback: packet: read type 20 [len=972,padding=10,comp=961,payload=961]
ssh_packet_process: Dispatching handler for packet type 20
ssh_list_kex: kex algos: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1
ssh_list_kex: server host key algo: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
ssh_list_kex: encryption client->server: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
ssh_list_kex: encryption server->client: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
ssh_list_kex: mac algo client->server: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
ssh_list_kex: mac algo server->client: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
ssh_list_kex: compression algo client->server: none,zlib@openssh.com
ssh_list_kex: compression algo server->client: none,zlib@openssh.com
ssh_list_kex: languages client->server: 
ssh_list_kex: languages server->client: 
ssh_kex_select_methods: Negotiated curve25519-sha256@libssh.org,ssh-ed25519,aes256-ctr,aes256-ctr,hmac-sha2-256,hmac-sha2-256,none,none,,
packet_send2: packet: wrote [len=44,padding=6,comp=37,payload=37]
ssh_socket_unbuffered_write: Enabling POLLOUT for socket
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLOUT ), out buffer 0
ssh_socket_pollcallback: sending control flow event
ssh_packet_socket_controlflow_callback: sending channel_write_wontblock callback
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLIN ), out buffer 0
ssh_packet_socket_callback: packet: read type 31 [len=188,padding=8,comp=179,payload=179]
ssh_packet_process: Dispatching handler for packet type 31
ssh_packet_dh_reply: Received SSH_KEXDH_REPLY
ssh_socket_unbuffered_write: Enabling POLLOUT for socket
packet_send2: packet: wrote [len=12,padding=10,comp=1,payload=1]
ssh_client_curve25519_reply: SSH_MSG_NEWKEYS sent
ssh_packet_socket_callback: Processing 112 bytes left in socket buffer
ssh_packet_socket_callback: packet: read type 21 [len=12,padding=10,comp=1,payload=1]
ssh_packet_process: Dispatching handler for packet type 21
ssh_packet_newkeys: Received SSH_MSG_NEWKEYS
crypt_set_algorithms2: Set output algorithm to aes256-ctr
crypt_set_algorithms2: Set HMAC output algorithm to hmac-sha2-256
crypt_set_algorithms2: Set input algorithm to aes256-ctr
crypt_set_algorithms2: Set HMAC input algorithm to hmac-sha2-256
ssh_pki_signature_verify: Going to verify a ssh-ed25519 type signature
ssh_packet_newkeys: Signature verified and valid
ssh_packet_socket_callback: Processing 96 bytes left in socket buffer
ssh_packet_socket_callback: packet: read type 7 [len=60,padding=6,comp=53,payload=53]
ssh_packet_process: Dispatching handler for packet type 7
ssh_packet_ext_info: Received SSH_MSG_EXT_INFO
ssh_packet_ext_info: Follows 1 extensions
ssh_packet_ext_info: Extension: server-sig-algs=<rsa-sha2-256,rsa-sha2-512>
ssh_connect: current state : 7
Found known server key: a2:b7:d8:4f:74:26:76:6c:25:42:09:03:6e:30:f0:7d:5d:16:11:25
packet_send2: packet: wrote [len=28,padding=10,comp=17,payload=17]
ssh_service_request: Sent SSH_MSG_SERVICE_REQUEST (service ssh-userauth)
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLOUT ), out buffer 64
ssh_socket_unbuffered_write: Enabling POLLOUT for socket
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLOUT ), out buffer 0
ssh_socket_pollcallback: sending control flow event
ssh_packet_socket_controlflow_callback: sending channel_write_wontblock callback
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLIN ), out buffer 0
ssh_packet_socket_callback: packet: read type 6 [len=28,padding=10,comp=17,payload=17]
ssh_packet_process: Dispatching handler for packet type 6
ssh_packet_service_accept: Received SSH_MSG_SERVICE_ACCEPT
ssh_socket_unbuffered_write: Enabling POLLOUT for socket
packet_send2: packet: wrote [len=44,padding=8,comp=35,payload=35]
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLOUT ), out buffer 0
ssh_socket_pollcallback: sending control flow event
ssh_packet_socket_controlflow_callback: sending channel_write_wontblock callback
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLIN ), out buffer 0
ssh_packet_socket_callback: packet: read type 51 [len=28,padding=12,comp=15,payload=15]
ssh_packet_process: Dispatching handler for packet type 51
ssh_packet_userauth_failure: Access denied for 'none'. Authentication that can continue: publickey
ssh_packet_userauth_failure: Access denied for 'none'. Authentication that can continue: publickey
ssh_userauth_publickey_auto: Trying to authenticate with C:\Users\mathe/.ssh/id_ed25519
ssh_pki_import_pubkey_file: Error opening C:\Users\mathe/.ssh/id_ed25519.pub: No such file or directory
ssh_pki_import_privkey_file: Error opening C:\Users\mathe/.ssh/id_ed25519: No such file or directory
ssh_userauth_publickey_auto: Private key C:\Users\mathe/.ssh/id_ed25519 doesn't exist.
ssh_userauth_publickey_auto: Trying to authenticate with C:\Users\mathe/.ssh/id_ecdsa
ssh_pki_import_pubkey_file: Error opening C:\Users\mathe/.ssh/id_ecdsa.pub: No such file or directory
ssh_pki_import_privkey_file: Error opening C:\Users\mathe/.ssh/id_ecdsa: No such file or directory
ssh_userauth_publickey_auto: Private key C:\Users\mathe/.ssh/id_ecdsa doesn't exist.
ssh_userauth_publickey_auto: Trying to authenticate with C:\Users\mathe/.ssh/id_rsa
ssh_key_algorithm_allowed: Checking rsa-sha2-512 with list <ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa,rsa-sha2-512,rsa-sha2-256,ssh-dss>
ssh_key_algorithm_allowed: Checking rsa-sha2-512 with list <ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa,rsa-sha2-512,rsa-sha2-256,ssh-dss>
ssh_socket_unbuffered_write: Enabling POLLOUT for socket
packet_send2: packet: wrote [len=604,padding=7,comp=596,payload=596]
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLOUT ), out buffer 0
ssh_socket_pollcallback: sending control flow event
ssh_packet_socket_controlflow_callback: sending channel_write_wontblock callback
ssh_socket_pollcallback: Poll callback on socket 1472 (POLLIN ), out buffer 0
ssh_packet_socket_callback: packet: read type 60 [len=572,padding=15,comp=556,payload=556]
ssh_packet_process: Dispatching handler for packet type 60
ssh_packet_userauth_pk_ok: Received SSH_USERAUTH_PK_OK/INFO_REQUEST/GSSAPI_RESPONSE
ssh_packet_userauth_pk_ok: Assuming SSH_USERAUTH_PK_OK
ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false
ssh_pki_openssh_import: Opening OpenSSH private key: ciphername: aes256-ctr, kdf: bcrypt, nkeys: 1

pki_private_key_decrypt: Decryption: 32 key, 16 IV, 16 rounds, zu bytes salt

At this point, my R crashes (by the way, please let me know if there's any sensitive information in the above log, so that I can remove it - I really don't know my way around these kinds of things).

From the unit tests within the ssh package, I can also reproduce this crash with the following 

ssh <- ssh_connect('dev.opencpu.org', keyfile = 'C:/Users/mathe/.ssh/id_rsa')

What I've tried

I'd be very happy to try anything you can think of. But I am quite ignorant of how ssh works, as well as how to debug fatal errors, so I'm not really sure what else can or should be attempted here. Also, I'm not really sure how to offer any help about reproducing the issue, but would love to hear if anyone else is experiencing the same on Windows 10.

Thanks so much in advance for any help!

jeroen commented 5 years ago

Thanks for the detailed report. It seems to be crashing when reading your key file. Perhaps there is a problem with the password entry. Is your private key in C:\Users\mathe\.ssh\id_rsa passworded? For example what happens when you run:

credentials::ssh_read_key()

Or can you try:

openssl::read_key('C:/Users/mathe/.ssh/id_rsa')

And see if this crashes? Can you also test if the askpass utility works:

 askpass::askpass("This is a test")
mathesong commented 5 years ago

Ok, so now I think we're making some good progress! These were awesome suggestions!

credentials::ssh_read_key()

credentials::ssh_read_key()

returns

Error: Unable to load key: C:\Users\mathe\.ssh\id_rsa

openssl::read_key()

openssl::read_key()

returns

Error in openssl::read_key("C:/Users/mathe/.ssh/id_rsa") : 
  OpenSSL does not support them fancy OPENSSH bcrypt/ed25519 keys

askpass::askpass

askpass::askpass("This is a test")

and I enter "test"

returns

"test"

fancy OPENSSH bcrypt/ed25519 keys

I guess this is the issue here. To create the ssh key, I following the instructions that I found on the analogsea github page, which sent me here: https://help.github.com/en/articles/connecting-to-github-with-ssh . I created the key with Git Bash, on a new Windows machine on which I'd just installed it the other day. So perhaps the new version of Git Bash is creating a new fancy type of key. I can look into creating an older one. But is it worth my making a PR that checks for the type of keyfile before trying to use it, and providing a suitable warning?

jeroen commented 5 years ago

Hmm interesting. But either way this should never crash, so there is an additional bug.

jeroen commented 5 years ago

But yes an immediate solution is to create a more standard type of key. If you want to do this, remove (create a backup first) C:\Users\mathe\.ssh\id_rsa and also C:\Users\mathe\.ssh\id_rsa.pub.

And then to generate a new key with:

credentials::ssh_keygen()
mathesong commented 5 years ago

Ok, so I generated new keys using both credentials::ssh_keygen() as well as through Git Bash ssh-keygen -t rsa -b 4096 -C "my@email.com", so in both cases they should not be ed25519 encrypted. However I get the same crash, and, using openssl::read_key(), I get the same error around the key being ed25519. So it seems to be rather that the error exists in identifying the encryption of the key itself.

Could this perhaps have something to do with my having generated the key using Windows? I wonder if it could be Windows newline operators or something like that messing up the identification of the encrpyion?

jeroen commented 5 years ago

OK i'll fire up a windows vm and try to reproduce this...

jeroen commented 5 years ago

Hmm I really don't understand how you end up with ed25519 keys. If I use windows ssh-keygen I get a regular rsa key:

snip

snip2

jeroen commented 5 years ago

What does the first line if your private key ~/.ssh/id_rsa file look like?

mathesong commented 5 years ago

When I use ssh_keygen, I'm using the one in Git Bash. Maybe that changes things? The first line of the private key reads as follows:

-----BEGIN OPENSSH PRIVATE KEY-----
b3BlbnNzaC1rZXktdjEAAAAACmFlczI1Ni1jdHIAAAAGYmNyeXB0AAAAGAAAABB+aiCaGe

Happy to help with any other details.

jeroen commented 5 years ago

Ok let me try to install the latest git for window and try again

jeroen commented 5 years ago

OK thanks I was able to generate such a key now indeed. I'm going to try to add support for this format but it isn't easy unfortunately. One way to work around is it generating your keys with the -pem flag like this ssh-keygen -pem

richfitz commented 5 years ago

I am seeing this key type on mac (mojave) too and can help test reading them if that's useful

jeroen commented 5 years ago

I'm tracking that in this issue: https://github.com/jeroen/openssl/issues/66

jeroen commented 5 years ago

@richfitz @mathesong I have added the openssh parsers in openssl. Run this in a clean R session:

remotes::install_github("jeroen/openssl")
mathesong commented 5 years ago

openssl::read_key("C:/Users/.../id_rsa") now works a charm. It returns the following:

[4096-bit rsa private key]
md5: d0c3f ...
jeroen commented 5 years ago

Does that also solve the crash when making the ssh connection?

mathesong commented 5 years ago

If I try 

ssh <- ssh_connect('dev.opencpu.org', keyfile = 'C:/Users/mathe/.ssh/id_rsa')

then I still crash out. But the ssh package doesn't seem to have been updated, and doesn't appear to have the openssl package as a dependency, so I don't know how this would have changed.

I'm not well enough versed in ssh and ssl to know how to use openssl reading in the id_rsa file to make the ssh connection, but if you could tell how, I could definitely give that a try!

jeroen commented 5 years ago

Ok thank you. So there are multiple issues here. I'll try to release the new openssl package first and then debug what is going on with the ssh crash.

jeroen commented 5 years ago

I think there is also a bug in libssh. @cryptomilk is libssh supposed to support encrypted private keys in the new openssh (bcrypt) format?

Update: also posted on the libssh mailing list

cryptomilk commented 5 years ago

I think this is fixed in master and will be soon released with libssh 0.9. I will branch 0.9 this week.

jeroen commented 5 years ago

@cryptomilk I tested this against the master branch and I don't think it is fixed.

cryptomilk commented 5 years ago

Ah thanks, Jakub will look into it.

jeroen commented 5 years ago

@mathesong can you try again with the dev version?

remotes::install_github("ropensci/ssh")
jeroen commented 5 years ago

I think this is fixed. If not, please feel free to open a new issue!

mathesong commented 5 years ago

@jeroen Sorry for being so slow to get back to you. It's been a pretty chaotic couple of weeks. The crash is now completely fixed, and all is well! Thank you so much for the fix!

When I tried running the analogsea command though, I kept on getting a new error of "Error: ssh failed", and I wanted to look into what was causing that, and whether there was still one last error along the way. I finally had some time today to get back to it, and I found the error and it was on my side.

For anyone who might come upon this page, the error above is in the docklet_create command. It should read as follows:

library(analogsea)

docklet_create(region="ams3", image="docker-18-04")  # The image must be docker, not ubuntu

d <- droplets()[[1]]

docklet_rstudio(d, user="test", password="test123", verbose=TRUE)

Thanks so much again for fixing this! It all works beautifully now!