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

SSH transport regression in 0.6.11 #886

Closed
dmacvicar opened this issue Sep 29, 2021 · 15 comments · Fixed by #925
Closed

SSH transport regression in 0.6.11 #886

dmacvicar opened this issue Sep 29, 2021 · 15 comments · Fixed by #925

Comments

@dmacvicar
Copy link
Owner

dmacvicar commented Sep 29, 2021

According to #864 comments, some users are experiencing regressions when using the ssh transport.

Please comment (in a single comment):

  • Your connection URL
  • TF_LOG=debug terraform plan output
  • make sure authorized_hosts on the server is correct
  • Any other error
  • Relevant info (client & server OS, etc)
  • env variable SSH_AUTH_SOCK
@klausenbusk
Copy link
Contributor

In my case specifying sshauth=privkey (the default is agent,privkey) solves the issue. I have ssh-agent running, but the key isn't added to it.

The Go documentation states:

	// Auth contains possible authentication methods to use with the
	// server. Only the first instance of a particular RFC 4252 method will
	// be used during authentication.
	Auth []AuthMethod

So that would explain why it isn't working when both options are specified (only the public keys from the first is used).

@oranenj FYI

@dmacvicar
Copy link
Owner Author

@klausenbusk if agent,privkey is specified, we add the auth method only if 1) SSH_AUTH_SOCK exists and 2) we can connect to the agent.
What do you mean the key is not added to it?

@klausenbusk
Copy link
Contributor

What do you mean the key is not added to it?

I only have some of my keys in the agent, in that case if agent,privkey is specified the key specified with keyfile= isn't tried as the library will only try the first instance of a particular RFC 4252 method (Go doc).

@mleone87
Copy link

mleone87 commented Oct 15, 2021

Not working for me too
URI

provider "libvirt" {
  uri = "qemu+ssh://[email protected]/system"
}

TF PLAN

2021-10-15T17:11:48.723+0200 [DEBUG] Adding temp file log sink: /tmp/terraform-log469900922
2021-10-15T17:11:48.723+0200 [INFO]  Terraform version: 1.0.9
2021-10-15T17:11:48.723+0200 [INFO]  Go runtime version: go1.17.1
2021-10-15T17:11:48.723+0200 [INFO]  CLI args: []string{"/usr/bin/terraform", "plan"}
2021-10-15T17:11:48.723+0200 [DEBUG] Attempting to open CLI config file: /home/mario/.terraformrc
2021-10-15T17:11:48.723+0200 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
2021-10-15T17:11:48.723+0200 [DEBUG] checking for credentials in "/home/mario/.terraform.d/plugins"
2021-10-15T17:11:48.723+0200 [DEBUG] ignoring non-existing provider search directory terraform.d/plugins
2021-10-15T17:11:48.723+0200 [DEBUG] will search for provider plugins in /home/mario/.terraform.d/plugins
2021-10-15T17:11:48.723+0200 [DEBUG] will search for provider plugins in /home/mario/.local/share/terraform/plugins
2021-10-15T17:11:48.723+0200 [DEBUG] ignoring non-existing provider search directory /home/mario/.local/share/flatpak/exports/share/terraform/plugins
2021-10-15T17:11:48.723+0200 [DEBUG] ignoring non-existing provider search directory /var/lib/flatpak/exports/share/terraform/plugins
2021-10-15T17:11:48.723+0200 [DEBUG] ignoring non-existing provider search directory /usr/local/share/terraform/plugins
2021-10-15T17:11:48.723+0200 [DEBUG] ignoring non-existing provider search directory /usr/share/terraform/plugins
2021-10-15T17:11:48.723+0200 [INFO]  CLI command args: []string{"plan"}
2021-10-15T17:11:48.724+0200 [DEBUG] New state was assigned lineage "6668a336-0ebe-a0bf-095b-7690864aa4ea"
2021-10-15T17:11:48.925+0200 [DEBUG] checking for provisioner in "."
2021-10-15T17:11:48.932+0200 [DEBUG] checking for provisioner in "/usr/bin"
2021-10-15T17:11:48.932+0200 [DEBUG] checking for provisioner in "/home/mario/.terraform.d/plugins"
2021-10-15T17:11:48.933+0200 [INFO]  Failed to read plugin lock file .terraform/plugins/linux_amd64/lock.json: open .terraform/plugins/linux_amd64/lock.json: no such file or directory
2021-10-15T17:11:48.933+0200 [INFO]  backend/local: starting Plan operation
2021-10-15T17:11:48.934+0200 [DEBUG] created provider logger: level=debug
2021-10-15T17:11:48.934+0200 [INFO]  provider: configuring client automatic mTLS
2021-10-15T17:11:48.944+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 args=[.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11]
2021-10-15T17:11:48.944+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17385
2021-10-15T17:11:48.944+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11
2021-10-15T17:11:48.950+0200 [INFO]  provider.terraform-provider-libvirt_v0.6.11: configuring server automatic mTLS: timestamp=2021-10-15T17:11:48.950+0200
2021-10-15T17:11:48.987+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.11: plugin address: address=/tmp/plugin697683969 network=unix timestamp=2021-10-15T17:11:48.987+0200
2021-10-15T17:11:48.987+0200 [DEBUG] provider: using plugin: version=5
2021-10-15T17:11:49.018+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
2021-10-15T17:11:49.019+0200 [DEBUG] No provider meta schema returned
2021-10-15T17:11:49.020+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17385
2021-10-15T17:11:49.020+0200 [DEBUG] provider: plugin exited
2021-10-15T17:11:49.020+0200 [INFO]  terraform: building graph: GraphTypeValidate
2021-10-15T17:11:49.020+0200 [DEBUG] ProviderTransformer: "libvirt_domain.default" (*terraform.NodeValidatableResource) needs provider["registry.terraform.io/dmacvicar/libvirt"]
2021-10-15T17:11:49.020+0200 [DEBUG] ReferenceTransformer: "libvirt_domain.default" references: []
2021-10-15T17:11:49.020+0200 [DEBUG] ReferenceTransformer: "provider[\"registry.terraform.io/dmacvicar/libvirt\"]" references: []
2021-10-15T17:11:49.021+0200 [DEBUG] Starting graph walk: walkValidate
2021-10-15T17:11:49.021+0200 [DEBUG] created provider logger: level=debug
2021-10-15T17:11:49.021+0200 [INFO]  provider: configuring client automatic mTLS
2021-10-15T17:11:49.030+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 args=[.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11]
2021-10-15T17:11:49.031+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17394
2021-10-15T17:11:49.031+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11
2021-10-15T17:11:49.036+0200 [INFO]  provider.terraform-provider-libvirt_v0.6.11: configuring server automatic mTLS: timestamp=2021-10-15T17:11:49.036+0200
2021-10-15T17:11:49.073+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.11: plugin address: address=/tmp/plugin466037037 network=unix timestamp=2021-10-15T17:11:49.073+0200
2021-10-15T17:11:49.073+0200 [DEBUG] provider: using plugin: version=5
2021-10-15T17:11:49.102+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
2021-10-15T17:11:49.103+0200 [DEBUG] No provider meta schema returned
2021-10-15T17:11:49.106+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17394
2021-10-15T17:11:49.106+0200 [DEBUG] provider: plugin exited
2021-10-15T17:11:49.106+0200 [INFO]  backend/local: plan calling Plan
2021-10-15T17:11:49.106+0200 [INFO]  terraform: building graph: GraphTypePlan
2021-10-15T17:11:49.107+0200 [DEBUG] ProviderTransformer: "libvirt_domain.default (expand)" (*terraform.nodeExpandPlannableResource) needs provider["registry.terraform.io/dmacvicar/libvirt"]
2021-10-15T17:11:49.107+0200 [DEBUG] ReferenceTransformer: "libvirt_domain.default (expand)" references: []
2021-10-15T17:11:49.107+0200 [DEBUG] ReferenceTransformer: "provider[\"registry.terraform.io/dmacvicar/libvirt\"]" references: []
2021-10-15T17:11:49.107+0200 [DEBUG] Starting graph walk: walkPlan
2021-10-15T17:11:49.107+0200 [DEBUG] created provider logger: level=debug
2021-10-15T17:11:49.107+0200 [INFO]  provider: configuring client automatic mTLS
2021-10-15T17:11:49.117+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 args=[.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11]
2021-10-15T17:11:49.117+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17403
2021-10-15T17:11:49.117+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11
2021-10-15T17:11:49.123+0200 [INFO]  provider.terraform-provider-libvirt_v0.6.11: configuring server automatic mTLS: timestamp=2021-10-15T17:11:49.123+0200
2021-10-15T17:11:49.160+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.11: plugin address: network=unix address=/tmp/plugin861317600 timestamp=2021-10-15T17:11:49.160+0200
2021-10-15T17:11:49.160+0200 [DEBUG] provider: using plugin: version=5
2021-10-15T17:11:49.188+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
2021-10-15T17:11:49.189+0200 [DEBUG] No provider meta schema returned
2021-10-15T17:11:49.191+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.11: 2021/10/15 17:11:49 [DEBUG] Configuring provider for 'qemu+ssh://[email protected]/system': &{map[uri:0xc0000ba3c0] <nil> <nil> 0xc000616080 map[] <nil> 0xc000616100 0xc000125170 0xc00068e280 false map[] {1 {0 0}} false false}
2021-10-15T17:11:49.227+0200 [INFO]  backend/local: plan operation completed
╷
│ Error: failed to dial libvirt: ssh: handshake failed: ssh: unable to authenticate, attempted methods [publickey none], no supported methods remain
│ 
│   with provider["registry.terraform.io/dmacvicar/libvirt"],
│   on provider.tf line 1, in provider "libvirt":
│    1: provider "libvirt" {
│ 
╵
2021-10-15T17:11:49.230+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17403
2021-10-15T17:11:49.230+0200 [DEBUG] provider: plugin exited

ssh-agent not used

ssh config(same connection url from plan virsh works)

Host 192.168.10.241
User mario
IdentityFile ~/.ssh/id_rsa_home

server side error

ott 15 17:14:59 arch-server sshd[3159]: userauth_pubkey: key type ssh-rsa not in PubkeyAcceptedAlgorithms [preauth]
ott 15 17:15:00 arch-server sshd[3159]: Connection closed by authenticating user mario 192.168.10.200 port 48698 [preauth]

if I do not make a copy of my ssh key with the default name the error is different(ssh config file gets ignored i think)

2021-10-15T17:16:00.707+0200 [DEBUG] Adding temp file log sink: /tmp/terraform-log3154352186
2021-10-15T17:16:00.707+0200 [INFO]  Terraform version: 1.0.9
2021-10-15T17:16:00.707+0200 [INFO]  Go runtime version: go1.17.1
2021-10-15T17:16:00.707+0200 [INFO]  CLI args: []string{"/usr/bin/terraform", "plan"}
2021-10-15T17:16:00.707+0200 [DEBUG] Attempting to open CLI config file: /home/mario/.terraformrc
2021-10-15T17:16:00.707+0200 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
2021-10-15T17:16:00.707+0200 [DEBUG] checking for credentials in "/home/mario/.terraform.d/plugins"
2021-10-15T17:16:00.707+0200 [DEBUG] ignoring non-existing provider search directory terraform.d/plugins
2021-10-15T17:16:00.707+0200 [DEBUG] will search for provider plugins in /home/mario/.terraform.d/plugins
2021-10-15T17:16:00.707+0200 [DEBUG] will search for provider plugins in /home/mario/.local/share/terraform/plugins
2021-10-15T17:16:00.707+0200 [DEBUG] ignoring non-existing provider search directory /home/mario/.local/share/flatpak/exports/share/terraform/plugins
2021-10-15T17:16:00.707+0200 [DEBUG] ignoring non-existing provider search directory /var/lib/flatpak/exports/share/terraform/plugins
2021-10-15T17:16:00.707+0200 [DEBUG] ignoring non-existing provider search directory /usr/local/share/terraform/plugins
2021-10-15T17:16:00.707+0200 [DEBUG] ignoring non-existing provider search directory /usr/share/terraform/plugins
2021-10-15T17:16:00.708+0200 [INFO]  CLI command args: []string{"plan"}
2021-10-15T17:16:00.708+0200 [DEBUG] New state was assigned lineage "6cb6e08e-392b-7a0c-180c-accf09c8fbe6"
2021-10-15T17:16:00.926+0200 [DEBUG] checking for provisioner in "."
2021-10-15T17:16:00.933+0200 [DEBUG] checking for provisioner in "/usr/bin"
2021-10-15T17:16:00.934+0200 [DEBUG] checking for provisioner in "/home/mario/.terraform.d/plugins"
2021-10-15T17:16:00.934+0200 [INFO]  Failed to read plugin lock file .terraform/plugins/linux_amd64/lock.json: open .terraform/plugins/linux_amd64/lock.json: no such file or directory
2021-10-15T17:16:00.934+0200 [INFO]  backend/local: starting Plan operation
2021-10-15T17:16:00.935+0200 [DEBUG] created provider logger: level=debug
2021-10-15T17:16:00.935+0200 [INFO]  provider: configuring client automatic mTLS
2021-10-15T17:16:00.945+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 args=[.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11]
2021-10-15T17:16:00.945+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17880
2021-10-15T17:16:00.945+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11
2021-10-15T17:16:00.951+0200 [INFO]  provider.terraform-provider-libvirt_v0.6.11: configuring server automatic mTLS: timestamp=2021-10-15T17:16:00.951+0200
2021-10-15T17:16:00.988+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.11: plugin address: address=/tmp/plugin289039778 network=unix timestamp=2021-10-15T17:16:00.988+0200
2021-10-15T17:16:00.988+0200 [DEBUG] provider: using plugin: version=5
2021-10-15T17:16:01.018+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
2021-10-15T17:16:01.018+0200 [DEBUG] No provider meta schema returned
2021-10-15T17:16:01.021+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17880
2021-10-15T17:16:01.021+0200 [DEBUG] provider: plugin exited
2021-10-15T17:16:01.021+0200 [INFO]  terraform: building graph: GraphTypeValidate
2021-10-15T17:16:01.021+0200 [DEBUG] ProviderTransformer: "libvirt_domain.default" (*terraform.NodeValidatableResource) needs provider["registry.terraform.io/dmacvicar/libvirt"]
2021-10-15T17:16:01.021+0200 [DEBUG] ReferenceTransformer: "libvirt_domain.default" references: []
2021-10-15T17:16:01.021+0200 [DEBUG] ReferenceTransformer: "provider[\"registry.terraform.io/dmacvicar/libvirt\"]" references: []
2021-10-15T17:16:01.021+0200 [DEBUG] Starting graph walk: walkValidate
2021-10-15T17:16:01.021+0200 [DEBUG] created provider logger: level=debug
2021-10-15T17:16:01.022+0200 [INFO]  provider: configuring client automatic mTLS
2021-10-15T17:16:01.031+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 args=[.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11]
2021-10-15T17:16:01.031+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17889
2021-10-15T17:16:01.031+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11
2021-10-15T17:16:01.037+0200 [INFO]  provider.terraform-provider-libvirt_v0.6.11: configuring server automatic mTLS: timestamp=2021-10-15T17:16:01.037+0200
2021-10-15T17:16:01.074+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.11: plugin address: address=/tmp/plugin197857021 network=unix timestamp=2021-10-15T17:16:01.074+0200
2021-10-15T17:16:01.074+0200 [DEBUG] provider: using plugin: version=5
2021-10-15T17:16:01.103+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
2021-10-15T17:16:01.104+0200 [DEBUG] No provider meta schema returned
2021-10-15T17:16:01.107+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17889
2021-10-15T17:16:01.107+0200 [DEBUG] provider: plugin exited
2021-10-15T17:16:01.107+0200 [INFO]  backend/local: plan calling Plan
2021-10-15T17:16:01.107+0200 [INFO]  terraform: building graph: GraphTypePlan
2021-10-15T17:16:01.107+0200 [DEBUG] ProviderTransformer: "libvirt_domain.default (expand)" (*terraform.nodeExpandPlannableResource) needs provider["registry.terraform.io/dmacvicar/libvirt"]
2021-10-15T17:16:01.108+0200 [DEBUG] ReferenceTransformer: "libvirt_domain.default (expand)" references: []
2021-10-15T17:16:01.108+0200 [DEBUG] ReferenceTransformer: "provider[\"registry.terraform.io/dmacvicar/libvirt\"]" references: []
2021-10-15T17:16:01.108+0200 [DEBUG] Starting graph walk: walkPlan
2021-10-15T17:16:01.108+0200 [DEBUG] created provider logger: level=debug
2021-10-15T17:16:01.108+0200 [INFO]  provider: configuring client automatic mTLS
2021-10-15T17:16:01.118+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 args=[.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11]
2021-10-15T17:16:01.118+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17899
2021-10-15T17:16:01.118+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11
2021-10-15T17:16:01.124+0200 [INFO]  provider.terraform-provider-libvirt_v0.6.11: configuring server automatic mTLS: timestamp=2021-10-15T17:16:01.124+0200
2021-10-15T17:16:01.163+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.11: plugin address: network=unix address=/tmp/plugin070799262 timestamp=2021-10-15T17:16:01.163+0200
2021-10-15T17:16:01.163+0200 [DEBUG] provider: using plugin: version=5
2021-10-15T17:16:01.192+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
2021-10-15T17:16:01.193+0200 [DEBUG] No provider meta schema returned
2021-10-15T17:16:01.195+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.11: 2021/10/15 17:16:01 [DEBUG] Configuring provider for 'qemu+ssh://[email protected]/system': &{map[uri:0xc0001383c0] <nil> <nil> 0xc0000ce2a0 map[] <nil> 0xc0000ce620 0xc000128288 0xc00070a460 false map[] {1 {0 0}} false false}
2021-10-15T17:16:01.195+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.11: 2021/10/15 17:16:01 [ERROR] Failed to read ssh key: %!w(*fs.PathError=&{open /home/mario/.ssh/id_rsa 2})
2021-10-15T17:16:01.195+0200 [INFO]  backend/local: plan operation completed
╷
│ Error: failed to dial libvirt: Could not configure SSH authentication methods
│ 
│   with provider["registry.terraform.io/dmacvicar/libvirt"],
│   on provider.tf line 1, in provider "libvirt":
│    1: provider "libvirt" {
│ 
╵
2021-10-15T17:16:01.197+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.11/linux_amd64/terraform-provider-libvirt_v0.6.11 pid=17899
2021-10-15T17:16:01.198+0200 [DEBUG] provider: plugin exited

some more ssh infos

sudo /usr/sbin/sshd -T | grep "(ciphers|macs|kexalgorithms)"

ciphers [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected]
macs [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1
kexalgorithms curve25519-sha256,[email protected],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
PORT   STATE SERVICE VERSION
22/tcp open  ssh     OpenSSH 8.8 (protocol 2.0)
| ssh2-enum-algos: 
|   kex_algorithms: (9)
|       curve25519-sha256
|       [email protected]
|       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
|   server_host_key_algorithms: (4)
|       rsa-sha2-512
|       rsa-sha2-256
|       ecdsa-sha2-nistp256
|       ssh-ed25519
|   encryption_algorithms: (6)
|       [email protected]
|       aes128-ctr
|       aes192-ctr
|       aes256-ctr
|       [email protected]
|       [email protected]
|   mac_algorithms: (10)
|       [email protected]
|       [email protected]
|       [email protected]
|       [email protected]
|       [email protected]
|       [email protected]
|       [email protected]
|       hmac-sha2-256
|       hmac-sha2-512
|       hmac-sha1
|   compression_algorithms: (2)
|       none
|_      [email protected]

@mc256
Copy link

mc256 commented Dec 6, 2021

I came across the same issue and was searching for an answer.

╷
│ Error: failed to dial libvirt: ssh: handshake failed: ssh: unable to authenticate, attempted methods [none publickey], no supported methods remain
│ 
│   with provider["registry.terraform.io/dmacvicar/libvirt"],
│   on k8s.tf line 10, in provider "libvirt":
│   10: provider "libvirt" {
│ 
╵

After checking the documentation on https://libvirt.org/uri.html
I added sshauth=privkey to the URI and it works!!!

qemu+ssh://<USERNAME>@<ADDRESS>/system?keyfile=<PATH TO PRIVATE KEY>&sshauth=privkey

I hope this could help.

@wmariuss
Copy link

wmariuss commented Dec 23, 2021

I came across the same issue and was searching for an answer.

╷
│ Error: failed to dial libvirt: ssh: handshake failed: ssh: unable to authenticate, attempted methods [none publickey], no supported methods remain
│ 
│   with provider["registry.terraform.io/dmacvicar/libvirt"],
│   on k8s.tf line 10, in provider "libvirt":
│   10: provider "libvirt" {
│ 
╵

After checking the documentation on https://libvirt.org/uri.html I added sshauth=privkey to the URI and it works!!!

qemu+ssh://<USERNAME>@<ADDRESS>/system?keyfile=<PATH TO PRIVATE KEY>&sshauth=privkey

I hope this could help.

Nop, to me this is not working. Also in 0.6.12 version.

@ratelbee
Copy link

qemu+ssh://user@host/system?sshauth=privkey&keyfile=./id_rsa

for me on macos(darwin_arm_64) terraform plan returned:

Error: failed to dial libvirt: ssh: handshake failed: ssh: unable to authenticate, attempted methods [none publickey], no supported methods remain

@dmacvicar
Copy link
Owner Author

@ratelbee can you provide a full debug log?

@dmacvicar
Copy link
Owner Author

dmacvicar commented Jan 23, 2022

Can you all please test with v0.6.13, just released and give me feedback? (see #916

@wmariuss
Copy link

On macOS Monterey 12.1 does not work:

2022-01-25T14:59:20.206+0200 [DEBUG] Adding temp file log sink: /var/folders/lt/w5ykf27n5_l68t0736kjslnc0000gn/T/terraform-log975558447
2022-01-25T14:59:20.207+0200 [INFO]  Terraform version: 1.0.11
2022-01-25T14:59:20.207+0200 [INFO]  Go runtime version: go1.16.4
2022-01-25T14:59:20.207+0200 [INFO]  CLI args: []string{"/usr/local/Cellar/tfenv/2.2.2/versions/1.0.11/terraform", "plan"}
2022-01-25T14:59:20.207+0200 [DEBUG] Attempting to open CLI config file: /Users/mariuss/.terraformrc
2022-01-25T14:59:20.207+0200 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
2022-01-25T14:59:20.207+0200 [INFO]  Loading CLI configuration from /Users/mariuss/.terraform.d/credentials.tfrc.json
2022-01-25T14:59:20.207+0200 [DEBUG] ignoring non-existing provider search directory terraform.d/plugins
2022-01-25T14:59:20.207+0200 [DEBUG] ignoring non-existing provider search directory /Users/mariuss/.terraform.d/plugins
2022-01-25T14:59:20.207+0200 [DEBUG] ignoring non-existing provider search directory /Users/mariuss/Library/Application Support/io.terraform/plugins
2022-01-25T14:59:20.207+0200 [DEBUG] ignoring non-existing provider search directory /Library/Application Support/io.terraform/plugins
2022-01-25T14:59:20.208+0200 [INFO]  CLI command args: []string{"plan"}
2022-01-25T14:59:20.209+0200 [DEBUG] New state was assigned lineage "a20af40a-fe53-97db-22c3-31562678a307"
2022-01-25T14:59:20.303+0200 [DEBUG] checking for provisioner in "."
2022-01-25T14:59:20.303+0200 [DEBUG] checking for provisioner in "/usr/local/Cellar/tfenv/2.2.2/versions/1.0.11"
2022-01-25T14:59:20.303+0200 [INFO]  Failed to read plugin lock file .terraform/plugins/darwin_amd64/lock.json: open .terraform/plugins/darwin_amd64/lock.json: no such file or directory
2022-01-25T14:59:20.303+0200 [INFO]  backend/local: starting Plan operation
2022-01-25T14:59:20.307+0200 [DEBUG] created provider logger: level=debug
2022-01-25T14:59:20.307+0200 [INFO]  provider: configuring client automatic mTLS
2022-01-25T14:59:20.341+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13 args=[.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13]
2022-01-25T14:59:20.344+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13 pid=88593
2022-01-25T14:59:20.344+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13
2022-01-25T14:59:20.355+0200 [INFO]  provider.terraform-provider-libvirt_v0.6.13: configuring server automatic mTLS: timestamp=2022-01-25T14:59:20.355+0200
2022-01-25T14:59:20.365+0200 [DEBUG] provider: using plugin: version=5
2022-01-25T14:59:20.365+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.13: plugin address: address=/var/folders/lt/w5ykf27n5_l68t0736kjslnc0000gn/T/plugin4115942423 network=unix timestamp=2022-01-25T14:59:20.365+0200
2022-01-25T14:59:20.400+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
2022-01-25T14:59:20.401+0200 [DEBUG] No provider meta schema returned
2022-01-25T14:59:20.403+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13 pid=88593
2022-01-25T14:59:20.403+0200 [DEBUG] provider: plugin exited
2022-01-25T14:59:20.403+0200 [DEBUG] created provider logger: level=debug
2022-01-25T14:59:20.403+0200 [INFO]  provider: configuring client automatic mTLS
2022-01-25T14:59:20.441+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5]
2022-01-25T14:59:20.444+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=88594
2022-01-25T14:59:20.444+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5
2022-01-25T14:59:20.455+0200 [INFO]  provider.terraform-provider-null_v3.1.0_x5: configuring server automatic mTLS: timestamp=2022-01-25T14:59:20.454+0200
2022-01-25T14:59:20.497+0200 [DEBUG] provider.terraform-provider-null_v3.1.0_x5: plugin address: address=/var/folders/lt/w5ykf27n5_l68t0736kjslnc0000gn/T/plugin897100473 network=unix timestamp=2022-01-25T14:59:20.497+0200
2022-01-25T14:59:20.498+0200 [DEBUG] provider: using plugin: version=5
2022-01-25T14:59:20.546+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-01-25T14:59:20.548+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=88594
2022-01-25T14:59:20.548+0200 [DEBUG] provider: plugin exited
2022-01-25T14:59:20.548+0200 [INFO]  terraform: building graph: GraphTypeValidate
2022-01-25T14:59:20.549+0200 [DEBUG] adding implicit provider configuration provider["registry.terraform.io/dmacvicar/libvirt"], implied first by module.kvm.libvirt_cloudinit_disk.init_disk
2022-01-25T14:59:20.549+0200 [DEBUG] adding implicit provider configuration provider["registry.terraform.io/hashicorp/null"], implied first by module.kvm.null_resource.provisioning
2022-01-25T14:59:20.549+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_cloudinit_disk.init_disk" (*terraform.NodeValidatableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.549+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_volume.custom_image" (*terraform.NodeValidatableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.549+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_volume.base_remote_image" (*terraform.NodeValidatableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.549+0200 [DEBUG] ProviderTransformer: "module.kvm.null_resource.provisioning" (*terraform.NodeValidatableResource) needs provider["registry.terraform.io/hashicorp/null"]
2022-01-25T14:59:20.549+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_volume.base_local_image" (*terraform.NodeValidatableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.549+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_domain.vm_creation" (*terraform.NodeValidatableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.550+0200 [DEBUG] pruning unused provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_cloudinit_disk.init_disk" references: [module.kvm.local.cloud_init_setup (expand) module.kvm.var.name (expand) module.kvm.local.network_config (expand) module.kvm.var.pool_name (expand)]
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.ssh_public_keys (expand)" references: []
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.vcpu (expand)" references: []
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.output.name (expand)" references: [module.kvm.libvirt_domain.vm_creation]
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_volume.custom_image" references: [module.kvm.var.volume_size (expand) module.kvm.var.local_os (expand) module.kvm.libvirt_volume.base_local_image module.kvm.libvirt_volume.base_remote_image module.kvm.var.name (expand) module.kvm.var.pool_name (expand)]
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.enable_provisioning (expand)" references: []
2022-01-25T14:59:20.551+0200 [INFO]  ReferenceTransformer: reference not found: "path.module"
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.local.network_config (expand)" references: [module.kvm.var.network_interfaces (expand) module.kvm.var.nameservers (expand)]
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.base_image (expand)" references: []
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.name (expand)" references: []
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.volume_format (expand)" references: []
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.disk_type (expand)" references: []
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.connection_timeout (expand)" references: []
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.volume_size (expand)" references: []
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.kvm_ssh_private_key (expand)" references: []
2022-01-25T14:59:20.551+0200 [INFO]  ReferenceTransformer: reference not found: "path.module"
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.output.inventory (expand)" references: [module.kvm.libvirt_domain.vm_creation module.kvm.var.ssh_user (expand) module.kvm.var.provisioning_ssh_private_key (expand)]
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_volume.base_remote_image" references: [module.kvm.var.local_os (expand) module.kvm.var.pool_name (expand) module.kvm.var.name (expand) module.kvm.var.volume_format (expand) module.kvm.local.os (expand) module.kvm.var.volume_format (expand)]
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.ssh_user (expand)" references: []
2022-01-25T14:59:20.551+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.network_interfaces (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.pool_name (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.privisioner_file_source (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.output.network (expand)" references: [module.kvm.libvirt_domain.vm_creation]
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "output.name" references: [module.kvm.output.name (expand)]
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.running (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.execute_remote_cmd (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm (close)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.null_resource.provisioning" references: [module.kvm.var.enable_provisioning (expand) module.kvm.libvirt_domain.vm_creation module.kvm.var.provisioning_ssh_private_key (expand) module.kvm.var.connection_timeout (expand) module.kvm.var.ssh_user (expand) module.kvm.libvirt_domain.vm_creation module.kvm.var.privisioner_file_source (expand) module.kvm.var.privisioner_file_dest (expand) module.kvm.var.execute_remote_cmd (expand)]
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.privisioner_file_dest (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.memory (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.kvm_server (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_volume.base_local_image" references: [module.kvm.var.local_os (expand) module.kvm.var.pool_name (expand) module.kvm.local.os (expand) module.kvm.var.volume_format (expand) module.kvm.var.name (expand) module.kvm.var.volume_format (expand)]
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_domain.vm_creation" references: [module.kvm.var.memory (expand) module.kvm.libvirt_cloudinit_disk.init_disk module.kvm.var.vcpu (expand) module.kvm.var.autostart (expand) module.kvm.var.running (expand) module.kvm.var.name (expand) module.kvm.var.network_interfaces (expand) module.kvm.var.name (expand) module.kvm.libvirt_volume.custom_image]
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.local_os (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.autostart (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.provisioning_ssh_private_key (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.where_is_os (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.nameservers (expand)" references: []
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.local.os (expand)" references: [module.kvm.var.local_os (expand) module.kvm.var.base_image (expand) module.kvm.var.where_is_os (expand)]
2022-01-25T14:59:20.552+0200 [INFO]  ReferenceTransformer: reference not found: "path.module"
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.local.cloud_init_setup (expand)" references: [module.kvm.var.ssh_user (expand) module.kvm.var.ssh_public_keys (expand)]
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "output.network" references: [module.kvm.output.network (expand)]
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "module.kvm.provider[\"registry.terraform.io/dmacvicar/libvirt\"]" references: [module.kvm.var.kvm_server (expand) module.kvm.var.kvm_ssh_private_key (expand)]
2022-01-25T14:59:20.552+0200 [DEBUG] ReferenceTransformer: "provider[\"registry.terraform.io/hashicorp/null\"]" references: []
2022-01-25T14:59:20.556+0200 [DEBUG] Starting graph walk: walkValidate
2022-01-25T14:59:20.557+0200 [DEBUG] created provider logger: level=debug
2022-01-25T14:59:20.557+0200 [INFO]  provider: configuring client automatic mTLS
2022-01-25T14:59:20.593+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5]
2022-01-25T14:59:20.597+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=88595
2022-01-25T14:59:20.597+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5
2022-01-25T14:59:20.607+0200 [INFO]  provider.terraform-provider-null_v3.1.0_x5: configuring server automatic mTLS: timestamp=2022-01-25T14:59:20.606+0200
2022-01-25T14:59:20.644+0200 [DEBUG] provider.terraform-provider-null_v3.1.0_x5: plugin address: address=/var/folders/lt/w5ykf27n5_l68t0736kjslnc0000gn/T/plugin153064734 network=unix timestamp=2022-01-25T14:59:20.644+0200
2022-01-25T14:59:20.644+0200 [DEBUG] provider: using plugin: version=5
2022-01-25T14:59:20.694+0200 [DEBUG] created provider logger: level=debug
2022-01-25T14:59:20.694+0200 [INFO]  provider: configuring client automatic mTLS
2022-01-25T14:59:20.731+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13 args=[.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13]
2022-01-25T14:59:20.737+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13 pid=88596
2022-01-25T14:59:20.737+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13
2022-01-25T14:59:20.751+0200 [INFO]  provider.terraform-provider-libvirt_v0.6.13: configuring server automatic mTLS: timestamp=2022-01-25T14:59:20.751+0200
2022-01-25T14:59:20.763+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.13: plugin address: address=/var/folders/lt/w5ykf27n5_l68t0736kjslnc0000gn/T/plugin494044918 network=unix timestamp=2022-01-25T14:59:20.763+0200
2022-01-25T14:59:20.763+0200 [DEBUG] provider: using plugin: version=5
2022-01-25T14:59:20.798+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
2022-01-25T14:59:20.799+0200 [DEBUG] No provider meta schema returned
2022-01-25T14:59:20.805+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13 pid=88596
2022-01-25T14:59:20.805+0200 [DEBUG] provider: plugin exited
2022-01-25T14:59:20.806+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-01-25T14:59:20.807+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=88595
2022-01-25T14:59:20.807+0200 [DEBUG] provider: plugin exited
2022-01-25T14:59:20.807+0200 [INFO]  backend/local: plan calling Plan
2022-01-25T14:59:20.808+0200 [INFO]  terraform: building graph: GraphTypePlan
2022-01-25T14:59:20.809+0200 [DEBUG] adding implicit provider configuration provider["registry.terraform.io/dmacvicar/libvirt"], implied first by module.kvm.libvirt_volume.base_local_image (expand)
2022-01-25T14:59:20.809+0200 [DEBUG] adding implicit provider configuration provider["registry.terraform.io/hashicorp/null"], implied first by module.kvm.null_resource.provisioning (expand)
2022-01-25T14:59:20.809+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_cloudinit_disk.init_disk (expand)" (*terraform.nodeExpandPlannableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.809+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_volume.custom_image (expand)" (*terraform.nodeExpandPlannableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.809+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_volume.base_local_image (expand)" (*terraform.nodeExpandPlannableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.809+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_volume.base_remote_image (expand)" (*terraform.nodeExpandPlannableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.809+0200 [DEBUG] ProviderTransformer: "module.kvm.libvirt_domain.vm_creation (expand)" (*terraform.nodeExpandPlannableResource) needs module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.809+0200 [DEBUG] ProviderTransformer: "module.kvm.null_resource.provisioning (expand)" (*terraform.nodeExpandPlannableResource) needs provider["registry.terraform.io/hashicorp/null"]
2022-01-25T14:59:20.809+0200 [DEBUG] pruning unused provider["registry.terraform.io/dmacvicar/libvirt"]
2022-01-25T14:59:20.810+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.autostart (expand)" references: []
2022-01-25T14:59:20.810+0200 [INFO]  ReferenceTransformer: reference not found: "path.module"
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.local.cloud_init_setup (expand)" references: [module.kvm.var.ssh_user (expand) module.kvm.var.ssh_public_keys (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.memory (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.privisioner_file_source (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.output.name (expand)" references: [module.kvm.libvirt_domain.vm_creation (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.vcpu (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.ssh_user (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.ssh_public_keys (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.local_os (expand)" references: []
2022-01-25T14:59:20.811+0200 [INFO]  ReferenceTransformer: reference not found: "path.module"
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.local.network_config (expand)" references: [module.kvm.var.network_interfaces (expand) module.kvm.var.nameservers (expand)]
2022-01-25T14:59:20.811+0200 [INFO]  ReferenceTransformer: reference not found: "path.module"
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.output.inventory (expand)" references: [module.kvm.libvirt_domain.vm_creation (expand) module.kvm.var.ssh_user (expand) module.kvm.var.provisioning_ssh_private_key (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "output.name" references: [module.kvm.output.name (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_volume.base_local_image (expand)" references: [module.kvm.var.local_os (expand) module.kvm.var.name (expand) module.kvm.var.volume_format (expand) module.kvm.var.volume_format (expand) module.kvm.var.pool_name (expand) module.kvm.local.os (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.disk_type (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.kvm_ssh_private_key (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.privisioner_file_dest (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_volume.base_remote_image (expand)" references: [module.kvm.var.local_os (expand) module.kvm.var.volume_format (expand) module.kvm.var.name (expand) module.kvm.var.volume_format (expand) module.kvm.local.os (expand) module.kvm.var.pool_name (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.volume_format (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.where_is_os (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.name (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.local.os (expand)" references: [module.kvm.var.local_os (expand) module.kvm.var.base_image (expand) module.kvm.var.where_is_os (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_domain.vm_creation (expand)" references: [module.kvm.var.memory (expand) module.kvm.libvirt_cloudinit_disk.init_disk (expand) module.kvm.var.vcpu (expand) module.kvm.var.autostart (expand) module.kvm.var.running (expand) module.kvm.var.name (expand) module.kvm.var.network_interfaces (expand) module.kvm.var.name (expand) module.kvm.libvirt_volume.custom_image (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.null_resource.provisioning (expand)" references: [module.kvm.var.enable_provisioning (expand) module.kvm.libvirt_domain.vm_creation (expand) module.kvm.var.provisioning_ssh_private_key (expand) module.kvm.var.connection_timeout (expand) module.kvm.var.ssh_user (expand) module.kvm.libvirt_domain.vm_creation (expand) module.kvm.var.connection_timeout (expand) module.kvm.var.ssh_user (expand) module.kvm.libvirt_domain.vm_creation (expand) module.kvm.var.provisioning_ssh_private_key (expand) module.kvm.var.privisioner_file_dest (expand) module.kvm.var.privisioner_file_source (expand) module.kvm.libvirt_domain.vm_creation (expand) module.kvm.var.provisioning_ssh_private_key (expand) module.kvm.var.ssh_user (expand) module.kvm.var.connection_timeout (expand) module.kvm.var.execute_remote_cmd (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.provisioning_ssh_private_key (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.kvm_server (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.volume_size (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.enable_provisioning (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.running (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.base_image (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_cloudinit_disk.init_disk (expand)" references: [module.kvm.local.network_config (expand) module.kvm.var.pool_name (expand) module.kvm.local.cloud_init_setup (expand) module.kvm.var.name (expand)]
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.pool_name (expand)" references: []
2022-01-25T14:59:20.811+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.execute_remote_cmd (expand)" references: []
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "provider[\"registry.terraform.io/hashicorp/null\"]" references: []
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "module.kvm (close)" references: []
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.network_interfaces (expand)" references: []
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "module.kvm.output.network (expand)" references: [module.kvm.libvirt_domain.vm_creation (expand)]
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "module.kvm.provider[\"registry.terraform.io/dmacvicar/libvirt\"]" references: [module.kvm.var.kvm_server (expand) module.kvm.var.kvm_ssh_private_key (expand)]
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "output.network" references: [module.kvm.output.network (expand)]
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "module.kvm (expand)" references: []
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "module.kvm.libvirt_volume.custom_image (expand)" references: [module.kvm.var.local_os (expand) module.kvm.libvirt_volume.base_local_image (expand) module.kvm.libvirt_volume.base_remote_image (expand) module.kvm.var.pool_name (expand) module.kvm.var.volume_size (expand) module.kvm.var.name (expand)]
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.connection_timeout (expand)" references: []
2022-01-25T14:59:20.812+0200 [DEBUG] ReferenceTransformer: "module.kvm.var.nameservers (expand)" references: []
2022-01-25T14:59:20.815+0200 [DEBUG] Starting graph walk: walkPlan
2022-01-25T14:59:20.816+0200 [DEBUG] created provider logger: level=debug
2022-01-25T14:59:20.816+0200 [INFO]  provider: configuring client automatic mTLS
2022-01-25T14:59:20.852+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5]
2022-01-25T14:59:20.856+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=88597
2022-01-25T14:59:20.856+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5
2022-01-25T14:59:20.865+0200 [INFO]  provider.terraform-provider-null_v3.1.0_x5: configuring server automatic mTLS: timestamp=2022-01-25T14:59:20.865+0200
2022-01-25T14:59:20.904+0200 [DEBUG] provider.terraform-provider-null_v3.1.0_x5: plugin address: network=unix address=/var/folders/lt/w5ykf27n5_l68t0736kjslnc0000gn/T/plugin258046672 timestamp=2022-01-25T14:59:20.904+0200
2022-01-25T14:59:20.904+0200 [DEBUG] provider: using plugin: version=5
2022-01-25T14:59:20.954+0200 [DEBUG] created provider logger: level=debug
2022-01-25T14:59:20.954+0200 [INFO]  provider: configuring client automatic mTLS
2022-01-25T14:59:20.995+0200 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13 args=[.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13]
2022-01-25T14:59:20.999+0200 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13 pid=88598
2022-01-25T14:59:21.000+0200 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13
2022-01-25T14:59:21.014+0200 [INFO]  provider.terraform-provider-libvirt_v0.6.13: configuring server automatic mTLS: timestamp=2022-01-25T14:59:21.014+0200
2022-01-25T14:59:21.025+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.13: plugin address: address=/var/folders/lt/w5ykf27n5_l68t0736kjslnc0000gn/T/plugin1813970997 network=unix timestamp=2022-01-25T14:59:21.025+0200
2022-01-25T14:59:21.025+0200 [DEBUG] provider: using plugin: version=5
2022-01-25T14:59:21.064+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
2022-01-25T14:59:21.065+0200 [DEBUG] No provider meta schema returned
2022-01-25T14:59:21.067+0200 [DEBUG] provider.terraform-provider-libvirt_v0.6.13: 2022/01/25 14:59:21 [DEBUG] Configuring provider for 'qemu+ssh://[email protected]/system?keyfile=$HOME/.ssh/mariuss_git': &{map[uri:0xc0004d0000] <nil> <nil> 0xc000274bc0 map[] <nil> 0xc000274c40 0xc00066c630 0xc000245ae0 false map[] {1 {0 0}} false false}
2022-01-25T14:59:22.255+0200 [INFO]  backend/local: plan operation completed
╷
│ Error: failed to dial libvirt: ssh: handshake failed: ssh: unable to authenticate, attempted methods [none publickey], no supported methods remain
│
│   with module.kvm.provider["registry.terraform.io/dmacvicar/libvirt"],
│   on ../../providers.tf line 11, in provider "libvirt":
│   11: provider "libvirt" {
│
╵
2022-01-25T14:59:22.256+0200 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-01-25T14:59:22.257+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/dmacvicar/libvirt/0.6.13/darwin_amd64/terraform-provider-libvirt_v0.6.13 pid=88598
2022-01-25T14:59:22.257+0200 [DEBUG] provider: plugin exited
2022-01-25T14:59:22.257+0200 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=88597
2022-01-25T14:59:22.257+0200 [DEBUG] provider: plugin exited

On Linux (Ubuntu 20.04) works.

@dmacvicar
Copy link
Owner Author

Please check:

#916 (comment)

@MikePadge
Copy link

MikePadge commented Jan 29, 2022

I came across the same issue and was searching for an answer.

╷
│ Error: failed to dial libvirt: ssh: handshake failed: ssh: unable to authenticate, attempted methods [none publickey], no supported methods remain
│ 
│   with provider["registry.terraform.io/dmacvicar/libvirt"],
│   on k8s.tf line 10, in provider "libvirt":
│   10: provider "libvirt" {
│ 
╵

After checking the documentation on https://libvirt.org/uri.html I added sshauth=privkey to the URI and it works!!!

qemu+ssh://<USERNAME>@<ADDRESS>/system?keyfile=<PATH TO PRIVATE KEY>&sshauth=privkey

I hope this could help.

Weird, I am seeing this now in the strangest way.
I have 3 machines.

One machine is failing and one machine is fine. Same exact hardware, same exact code, same ssh config, same key.... same remote endpoint.
Both - Terraform 1.1.4
Both - libvirt v0.6.13
Both - 4.19.0-18-amd64

Working Machine URI
qemu+ssh://<username>@<address>/system

Failing machine
Set to the above uri scheme.
It started working when set to
qemu+ssh://<USERNAME>@<ADDRESS>/system?keyfile=<PATH TO PRIVATE KEY>&sshauth=privkey

Looks like the failing machine has had something introduced in one of the more recent golang patches

Failing = go version go1.16.5 linux/amd64

Working machine = go version go1.16 linux/amd64

@dmacvicar
Copy link
Owner Author

@MikePadge I'd be skeptical about that. Please check which key is being tried in each case by looking at the logs of the ssh server in both cases.

As we tracked down the issue, it is because servers don't accept RSA keys with SHA1 signatures. Golang client does not support RSA+SHA256 sigs nor the extension to negotiate the algorithm to use.

I have posted a branch with a fix I reproduced locally in #916 (comment)

If you know how to build the provider locally, check that comment for instructions and check if that fix works for you. Feedback is crucial to make a release with the fix.

dmacvicar added a commit that referenced this issue Jan 31, 2022
The fork adds the following patches:

- ssh: add support for extension negotiation (rfc 8308)
  golang/crypto#197
- ssh: use extension negotiation (rfc 8308) in ssh clients
  rmohr/crypto@e4ed966

Closes: #916
Closes: #886
@dmacvicar
Copy link
Owner Author

https://github.com/dmacvicar/terraform-provider-libvirt/releases/tag/v0.6.14 should be available in the registry soon.

@pnsafonov
Copy link

I can propose this workaround.

Make remote unix socket forwarding to local port with root access on remote host:
ssh -nNT -L localhost:5000:/run/libvirt/libvirt-sock [email protected]

And use connection string to local port:
qemu+tcp://localhost:5000/system

It's working for me.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

8 participants