Regression since 0.18/0.19 - passphrased .key "Dying because - Broken transport; encountered EOF"

[mchubby]

Summary

Recently upgraded from 4.12 to 4.17, now SSH jobs fail.
We were already using SSHJ jobs without issue. The private key is password-protected.

Details

service.log has this output for the relevant execution:

[2023-11-03T11:00:48,136] ERROR services.ExecutionUtilService - Execution failed: 988 in project sshtest: [Workflow result: , step failures: {1=NodeDispatchFailure: Failed dispatching to node node00: com.plugin.sshjplugin.SSHJBuilder$BuilderException: Exhausted available authentication methods}, Node failures: {node00=[Unknown: com.plugin.sshjplugin.SSHJBuilder$BuilderException: Exhausted available authentication methods]}, flow control: Continue, status: failed]
[2023-11-03T11:02:47,553] ERROR transport.TransportImpl - Dying because - Broken transport; encountered EOF
net.schmizz.sshj.transport.TransportException: Broken transport; encountered EOF
        at net.schmizz.sshj.transport.Reader.run(Reader.java:58) [sshj-0.35.0.jar:?]

@MegaDrive68k can you please take a look?

Here is the test case:

/var/rundeck/gitroot/sshtest-nodes.yml

node00:
  nodename: node00
  hostname: MYNODE(your IP/FQDN here)
  osFamily: unix
  username: root
  ssh-key-passphrase-option: "option.sshKeyPassphrase"

• SSH ed25519 passphrased key at /var/rundeck/gitroot/sshtest-passphrased.key
• pubkey in remote server's authorized_keys. Server is a Debian 12 OpenSSH service.
• tested successfully on the CLI (ssh -i ...)

sshtest project: only defines the .key path and nodes (SSHJ is now default in 4.17).

#Fri Nov 03 11:14:36 CET 2023
#edit below
project.description=
project.disable.executions=false
project.disable.schedule=false
project.execution.history.cleanup.batch=500
project.execution.history.cleanup.enabled=false
project.execution.history.cleanup.retention.days=60
project.execution.history.cleanup.retention.minimum=50
project.execution.history.cleanup.schedule=0 0 0 1/1 * ? *
project.jobs.gui.groupExpandLevel=1
project.label=
project.later.executions.disable=false
project.later.executions.enable=false
project.later.schedule.disable=false
project.later.schedule.enable=false
project.name=sshtest
project.nodeCache.enabled=true
project.nodeCache.firstLoadSynch=true
project.output.allowUnsanitized=false
project.retry-counter=3
project.ssh-authentication=privateKey
project.ssh-keypath=/var/rundeck/gitroot/sshtest-passphrased.key
resources.source.1.config.file=/var/rundeck/gitroot/sshtest-nodes.yml
resources.source.1.config.requireFileExists=true
resources.source.1.config.writeable=true
resources.source.1.type=file
service.FileCopier.default.provider=sshj-scp
service.NodeExecutor.default.provider=sshj-ssh

Job definition
000_diag_SingleCommand.yaml

- defaultTab: output
  description: ''
  executionEnabled: true
  group: 000_diag
  id: e1ac9f1e-98c6-4acd-8b31-8261f6277ccf
  loglevel: INFO
  name: SingleCommand
  nodeFilterEditable: false
  nodefilters:
    dispatch:
      excludePrecedence: true
      keepgoing: false
      rankOrder: ascending
      successOnEmptyNodeFilter: false
      threadcount: '1'
    filter: 'name: node00 '
  nodesSelectedByDefault: true
  options:
  - name: sshKeyPassphrase
    required: true
    secure: true
  plugins:
    ExecutionLifecycle: null
  scheduleEnabled: true
  sequence:
    commands:
    - script: |-
        hostname
        echo "whoami = $(whoami)"
        echo "logname = $(logname)"
    keepgoing: false
    strategy: parallel
  uuid: e1ac9f1e-98c6-4acd-8b31-8261f6277ccf

Action: run job with debug output, providing the key passphrase.

Expected Results

Provided script commands are executed (see attached log output file Output986-SSHJv0.1.7.txt)

To obtain this execution result, default plugin v0.19 was uninstalled, then the v0.17 jar was installed serverwide.

Observed Results

Using SSH plugin v0.19, SSH connection fails, therefore the job does too.

Nodeside, OpenSSH logs a new (tcp) connection and that's it.

see attached log for full output
Output988-SSHJv0.1.9.txt

1: Workflow step executing: ScriptFileItem{script=[62 chars]}
preparing for sequential execution on 1 nodes
Executing command on node: node00, NodeEntryImpl{tags=[], attributes={nodename=node00, hostname=MYNODE, osFamily=unix, ssh-key-passphrase-option=option.sshKeyPassphrase, username=root}, project='null'}
[workflow] beginExecuteNodeStep(node00): NodeDispatch: ScriptFileItem{script=[62 chars]}
[sshj-scp] copying file
[sshj-scp] username: root
[sshj-scp] hostname: MYNODE
[sshj-scp] port: null
[sshj-scp] username: root
[sshj-scp] init SSHJDefaultConfig
[sshj-scp] setting timeouts
[sshj-scp] getConnectTimeout timeout: 0
[sshj-scp] getTimeout timeout: 0
[sshj-scp] keepAliveInterval: 0
[sshj-scp] retry: false
[sshj-scp] retryCount: 3
[sshj-scp] adding loadKnownHosts
[sshj-scp] open connection
[sshj-scp] connection done
Authenticating using private key
[sshj-debug] Using SSH Keyfile: /var/rundeck/gitroot/sshtest-passphrased.key
[sshj-scp] Connection fail: Exhausted available authentication methods
[workflow] finishExecuteNodeStep(node00): NodeDispatch: Unknown: Exhausted available authentication methods
Failed dispatching to node node00: com.plugin.sshjplugin.SSHJBuilder$BuilderException: Exhausted available authentication methods
Failed dispatching to node node00: com.dtolabs.rundeck.core.execution.workflow.steps.node.NodeStepException: com.plugin.sshjplugin.SSHJBuilder$BuilderException: Exhausted available authentication methods
	at com.dtolabs.rundeck.core.execution.ExecutionServiceImpl.executeNodeStep(ExecutionServiceImpl.java:221)
	at com.dtolabs.rundeck.core.execution.dispatch.SequentialNodeDispatcher.dispatch(SequentialNodeDispatcher.java:130)
	at com.dtolabs.rundeck.core.execution.dispatch.SequentialNodeDispatcher.dispatch(SequentialNodeDispatcher.java:61)
	at com.dtolabs.rundeck.core.execution.ExecutionServiceImpl.dispatchToNodesWith(ExecutionServiceImpl.java:263)
	at com.dtolabs.rundeck.core.execution.ExecutionServiceImpl.dispatchToNodes(ExecutionServiceImpl.java:234)
	at com.dtolabs.rundeck.core.execution.workflow.steps.NodeDispatchStepExecutor.executeWorkflowStep(NodeDispatchStepExecutor.java:66)
	at com.dtolabs.rundeck.core.execution.ExecutionServiceImpl.executeStep(ExecutionServiceImpl.java:111)
	at com.dtolabs.rundeck.core.execution.workflow.BaseWorkflowExecutor.executeWFItem(BaseWorkflowExecutor.java:285)
	at com.dtolabs.rundeck.core.execution.workflow.BaseWorkflowExecutor.executeWorkflowStep(BaseWorkflowExecutor.java:681)
	at com.dtolabs.rundeck.core.execution.workflow.engine.StepCallable.apply(StepCallable.java:71)
	at com.dtolabs.rundeck.core.execution.workflow.engine.StepOperation.apply(StepOperation.java:76)
	at com.dtolabs.rundeck.core.execution.workflow.engine.StepOperation.apply(StepOperation.java:32)
	at com.dtolabs.rundeck.core.rules.WorkflowEngineOperationsProcessor.lambda$beginOperation$1(WorkflowEngineOperationsProcessor.java:323)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:131)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:75)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:82)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: com.plugin.sshjplugin.SSHJBuilder$BuilderException: Exhausted available authentication methods
	at com.plugin.sshjplugin.model.SSHJBase.connect(SSHJBase.java:134)
	at com.plugin.sshjplugin.SSHJFileCopierPlugin.copyFile(SSHJFileCopierPlugin.java:163)
	at com.plugin.sshjplugin.SSHJFileCopierPlugin.copyFile(SSHJFileCopierPlugin.java:96)
	at com.dtolabs.rundeck.core.execution.ExecutionServiceImpl.fileCopyFile(ExecutionServiceImpl.java:320)
	at com.dtolabs.rundeck.core.execution.workflow.steps.node.impl.DefaultScriptFileNodeStepUtils.executeScriptFile(DefaultScriptFileNodeStepUtils.java:119)
	at com.dtolabs.rundeck.core.execution.workflow.steps.node.impl.ScriptFileNodeStepExecutor.executeNodeStep(ScriptFileNodeStepExecutor.java:81)
	at com.dtolabs.rundeck.core.execution.ExecutionServiceImpl.executeNodeStep(ExecutionServiceImpl.java:207)
	... 18 more

Note: I tried setting -XX:MaxJavaStackTraceDepth=2000 in /etc/defaults/rundeckd but the exception stackdump is still incomplete.

Remarks

Using a non-password-protected key works. i.e.

• remove the job option
• remove key protection ssh-keygen -p -f ...
• remove the nodes.yaml ssh-key-passphrase-option entry (optional)

[MegaDrive68k]

Confirmed @mchubby Thanks for the detailed information to reproduce!

[mchubby]

Related to #20

When passphrase is not in a storage path (i.e. secure option) getPrivateKeyPassphrase() is no longer called

sshj-plugin/src/main/java/com/plugin/sshjplugin/model/SSHJAuthentication.java

Lines 34 to 47 in 5ea2ded

	case privateKey:
	logger.log(3, "Authenticating using private key");
	String privateKeyStoragePath = connectionParameters.getPrivateKeyStoragePath();
	String privateKeyFileSystemPath = connectionParameters.getPrivateKeyFilePath();
	String passphrasePath = connectionParameters.getPrivateKeyPassphraseStoragePath();
	FileKeyProvider keys = null;
	if(passphrasePath != null){
	try{
	passphrase = connectionParameters.getPrivateKeyPassphrase(passphrasePath);
	} catch (Exception e) {
	throw new SSHJBuilder.BuilderException("Failed to read SSH Passphrase stored at path: " + passphrasePath);
	}
	}

vs.

sshj-plugin/src/main/java/com/plugin/sshjplugin/model/SSHJAuthentication.java

Lines 45 to 50 in 7fc6c3e

	String passphrasePath = connectionParameters.getPrivateKeyPassphraseStoragePath();
	try{
	passphrase = connectionParameters.getPrivateKeyPassphrase(passphrasePath);
	} catch (Exception e) {
	throw new SSHJBuilder.BuilderException("Failed to read SSH Passphrase stored at path: " + passphrasePath);
	}