[JIRA] (JENKINS-57765) No output returned from sshCommand

0 views
Skip to first unread message

ehamrick@merkleinc.com (JIRA)

unread,
May 30, 2019, 3:52:02 PM5/30/19
to jenkinsc...@googlegroups.com
Evan Hamrick created an issue
 
Jenkins / Bug JENKINS-57765
No output returned from sshCommand
Issue Type: Bug Bug
Assignee: Naresh Rayapati
Components: ssh-steps-plugin
Created: 2019-05-30 15:51
Environment: Jenkins 2.164.1 ssh-steps 1.2.1
Priority: Minor Minor
Reporter: Evan Hamrick

Setting up a test case to verify a few things at once--ssh-steps, service account creation, and so forth, by running a simple command on a remote server and getting the output. I'm seeing that the ssh connection seems to work and the command is executed, but output doesn't reliably come back.

Looking through the console output I can't help but notice that

logging = none

is in the command parameters, but I can't find that documented anywhere. Could that be part of the problem?

 

Here is my script: 

def remote = [:]
remote.name = 'Test run'
remote.host = 'host'
remote.filetransfer = 'SCP'
remote.allowAnyHosts = true
remote.appendName = true
remote.logLevel = 'FINEST'
remote.pty = true
node 
{
 withCredentials([usernamePassword(credentialsId: 'user', passwordVariable: 'p', usernameVariable: 'u')]) 
 {
 remote.user = u
 remote.password = p
stage('Remote SSH') 
 {
 sshCommand remote: remote, command: "cd / && ls"
 }
 }
}

and the output:

Started by user User
Running in Durability level: MAX_SURVIVABILITY
[Pipeline] Start of Pipeline (hide)
[Pipeline] node
Running on ESG-AGENT in /var/jenkins-agent/workspace/name
[Pipeline] {
[Pipeline] withCredentials
Masking only exact matches of $u or $p
[Pipeline] {
[Pipeline] stage
[Pipeline] { (Remote SSH)
[Pipeline] sshCommand
Using default settings: {fileTransfer=sftp, jschLog=false, retryWaitSec=0, timeoutSec=0, pty=false, authentications=[publickey, keyboard-interactive, password], agentForwarding=false, keepAliveSec=60, sudoPath=sudo, dryRun=false, encoding=UTF-8, retryCount=0, logging=slf4j, knownHosts=/var/jenkins-agent/.ssh/known_hosts, ignoreError=false, agent=false}
Using global settings: {}
Using per-service settings: {}
Using per-remote settings: {jschLog=true, pty=true, user=****, interaction=org.jenkinsci.plugins.sshsteps.SSHService$_defineRemote_closure1$_closure8$_closure9@b1ae59f, dryRun=false, logging=none, knownHosts=allowAnyHosts, ignoreError=false, password=...}
Enabled JSch logging on Thread[pool-1-thread-7098 for channel id=4086,5,main]
Connecting to Test run[host:22] with {keepAliveSec=60, retryCount=0, retryWaitSec=0, knownHosts=allowAnyHosts, timeoutSec=0, agent=false, authentications=[publickey, keyboard-interactive, password], password=..., user=****}
Host key checking is off. It may be vulnerable to man-in-the-middle attacks.
Using password authentication for Test run[host:22]
[jsch] Connecting to host port 22
[jsch] Connection established
[jsch] Remote version string: SSH-2.0-OpenSSH_5.3
[jsch] Local version string: SSH-2.0-JSCH-0.1.54
[jsch] CheckCiphers: aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-ctr,arcfour,arcfour128,arcfour256
[jsch] CheckKexes: diffie-hellman-group14-sha1,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521
[jsch] CheckSignatures: ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
[jsch] SSH_MSG_KEXINIT sent
[jsch] SSH_MSG_KEXINIT received
[jsch] kex: server: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
[jsch] kex: server: ssh-rsa,ssh-dss
[jsch] kex: server: aes128-ctr,aes192-ctr,aes256-ctr
[jsch] kex: server: aes128-ctr,aes192-ctr,aes256-ctr
[jsch] kex: server: hmac-sha1,uma...@openssh.com,hmac-ripemd160,hmac-sha2-256,hmac-sha2-512,hmac-ri...@openssh.com
[jsch] kex: server: hmac-sha1,uma...@openssh.com,hmac-ripemd160,hmac-sha2-256,hmac-sha2-512,hmac-ri...@openssh.com
[jsch] kex: server: none,zl...@openssh.com
[jsch] kex: server: none,zl...@openssh.com
[jsch] kex: server: 
[jsch] kex: server: 
[jsch] kex: client: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
[jsch] kex: client: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
[jsch] kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc
[jsch] kex: client: aes128-ctr,aes128-cbc,3des-ctr,3des-cbc,blowfish-cbc,aes192-ctr,aes192-cbc,aes256-ctr,aes256-cbc
[jsch] kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96
[jsch] kex: client: hmac-md5,hmac-sha1,hmac-sha2-256,hmac-sha1-96,hmac-md5-96
[jsch] kex: client: none
[jsch] kex: client: none
[jsch] kex: client: 
[jsch] kex: client: 
[jsch] kex: server->client aes128-ctr hmac-sha1 none
[jsch] kex: client->server aes128-ctr hmac-sha1 none
[jsch] SSH_MSG_KEXDH_INIT sent
[jsch] expecting SSH_MSG_KEXDH_REPLY
[jsch] ssh_rsa_verify: signature true
[jsch] Permanently added 'host' (RSA) to the list of known hosts.
[jsch] SSH_MSG_NEWKEYS sent
[jsch] SSH_MSG_NEWKEYS received
[jsch] SSH_MSG_SERVICE_REQUEST sent
[jsch] SSH_MSG_SERVICE_ACCEPT received
[jsch] Authentications that can continue: publickey,keyboard-interactive,password
[jsch] Next authentication method: publickey
[jsch] Authentications that can continue: keyboard-interactive,password
[jsch] Next authentication method: keyboard-interactive
[jsch] Authentication succeeded (keyboard-interactive).
Connected to Test run[host:22] (SSH-2.0-OpenSSH_5.3)
Executing command on Test run[host:22]: cd / && ls: {pty=true, encoding=UTF-8, agentForwarding=false, logging=none, timeoutSec=0, ignoreError=false, interaction=org.jenkinsci.plugins.sshsteps.SSHService$_defineRemote_closure1$_closure8$_closure9@b1ae59f}
[Pipeline] }
[Pipeline] // stage
[Pipeline] }
[Pipeline] // withCredentials
[Pipeline] }
[Pipeline] // node
[Pipeline] End of Pipeline
Finished: SUCCESS
Add Comment Add Comment
 
This message was sent by Atlassian Jira (v7.11.2#711002-sha1:fdc329d)

naresh.rayapati@gmail.com (JIRA)

unread,
May 30, 2019, 4:12:02 PM5/30/19
to jenkinsc...@googlegroups.com
Naresh Rayapati commented on Bug JENKINS-57765
 
Re: No output returned from sshCommand

Evan Hamrick By chance are you running on k8s agents? or some kind of dynamic agents? if so I would sleep at the end for about couple of seconds to catch up the logs

naresh.rayapati@gmail.com (JIRA)

unread,
May 30, 2019, 4:14:02 PM5/30/19
to jenkinsc...@googlegroups.com
def remote = [:]
remote.name = 'Test run'
remote.host = 'host'
remote.filetransfer = 'SCP'
remote.allowAnyHosts = true
remote.appendName = true
remote.logLevel = 'FINEST'
remote.pty = true
node 
{
 withCredentials([usernamePassword(credentialsId: 'user', passwordVariable: 'p', usernameVariable: 'u')]) 
 {
 remote.user = u
 remote.password = p
stage('Remote SSH') 
 {
 sshCommand remote: remote, command: "cd / && ls"
 }
 }
sleep 5
}

ehamrick@merkleinc.com (JIRA)

unread,
May 30, 2019, 4:25:01 PM5/30/19
to jenkinsc...@googlegroups.com

Hey Naresh Rayapati, adding a sleep seems to work but I have to admit I don't understand why–it's like the sshCommand runs successfully but Jenkins closes the job before the result comes back? 

ehamrick@merkleinc.com (JIRA)

unread,
May 30, 2019, 4:47:03 PM5/30/19
to jenkinsc...@googlegroups.com
Evan Hamrick edited a comment on Bug JENKINS-57765
Hey [~nrayapati], adding a sleep seems to work but I have to admit I don't understand why–it's like the sshCommand runs successfully but Jenkins closes the job before the result comes back? 


Edit- Doing some editing for log truncation specifically I found this, seems pretty similar to what I"m seeing: https://issues.jenkins-ci.org/browse/JENKINS-29198

ehamrick@merkleinc.com (JIRA)

unread,
May 30, 2019, 4:51:33 PM5/30/19
to jenkinsc...@googlegroups.com
Evan Hamrick edited a comment on Bug JENKINS-57765
Hey [~nrayapati], adding a sleep seems to work but I have to admit I don't understand why–it's like the sshCommand runs successfully but Jenkins closes the job before the result comes back? 


Edit- Doing some editing searching for log truncation specifically I found this, seems pretty similar to what I"m seeing: https://issues.jenkins-ci.org/browse/JENKINS-29198

ehamrick@merkleinc.com (JIRA)

unread,
May 30, 2019, 4:52:01 PM5/30/19
to jenkinsc...@googlegroups.com

naresh.rayapati@gmail.com (JIRA)

unread,
May 31, 2019, 12:03:04 AM5/31/19
to jenkinsc...@googlegroups.com

Evan Hamrick Even I am trying to understand more about this behavior, but so far my understanding was that for these kind of quick commands like less than mill seconds there is always a chance that file streams would get close before the entire output being sent to it. so kind of hack but thats the option that we are using, as it is just a couple of seconds for the job that we are running for hours

ehamrick@merkleinc.com (JIRA)

unread,
May 31, 2019, 1:20:01 PM5/31/19
to jenkinsc...@googlegroups.com

Thanks for your help and understanding with incorrectly opening the bug against ssh-steps  

ehamrick@merkleinc.com (JIRA)

unread,
May 31, 2019, 1:21:01 PM5/31/19
to jenkinsc...@googlegroups.com
Evan Hamrick edited a comment on Bug JENKINS-57765
Thanks for your help and understanding with incorrectly opening the bug against ssh-steps :)  Should I change it to core for further investigation or close it?

ehamrick@merkleinc.com (JIRA)

unread,
May 31, 2019, 1:28:02 PM5/31/19
to jenkinsc...@googlegroups.com
Evan Hamrick edited a comment on Bug JENKINS-57765
Thanks for your help and understanding with incorrectly opening   :)  Should we leave the bug against here with ssh-steps :)  Should I , or change it to core for further investigation or close it ?

naresh.rayapati@gmail.com (JIRA)

unread,
Jun 16, 2019, 2:27:03 PM6/16/19
to jenkinsc...@googlegroups.com
Naresh Rayapati closed an issue as Won't Fix
 
Change By: Naresh Rayapati
Status: Open Closed
Resolution: Won't Fix

naresh.rayapati@gmail.com (JIRA)

unread,
Jun 16, 2019, 2:27:03 PM6/16/19
to jenkinsc...@googlegroups.com
Naresh Rayapati commented on Bug JENKINS-57765
 
Re: No output returned from sshCommand

Don't know if I can do anything about this at the moment, I will add some docs with the next release.

Closing this now, probably once it is becomes really problematic I will reopen or create a new one. Thanks for reporting Evan Hamrick.

jielpe-cblv38@protonmail.com (JIRA)

unread,
Nov 6, 2019, 10:16:02 AM11/6/19
to jenkinsc...@googlegroups.com

Hello,

Well, I really don't understand how you can consider this as not problematic.
It is really a pain indeed !

Let's consider a user who wants to make some quick trials, or even a user who tries to avoid using a shell step with some more or less complex script to simply test a ssh connection. He finds the sshCommand and thinks ok, great ! I found what I need ! I have a simple way of testing, enclosing the sshCommand within a try / catch and calling a simple uname or ls command.
... But he is totally disappointed because ... ok, there is no problem. It seems to work, but he is not sure because he has no output. And he need the output fir this or that reason because he wants to check something.

That's my use case... even worst in fact. Because my organisation wants to set a bunch of test cases to validate the ssh step in order to be sure it can be used it in production, and later on to have some regression tests when upgrading jenkins and plugins. And at the first trial, I fall into this trap.

How can I say to people supporting Jenkins... hey men, that's OK. It works as a charm and everybody can use it with no worries !

So, no, it is not a cosmetic problem. It is a real one because it is more or less related to some unpredictable response time. I am not sure if 5 sec is enough. Perhaps it is less (and I loose time) perhaps it is more, and I both loose information and fail a test which is actually a success.

So, please, could you consider again this as bug to fix ?

Thanks for your help.
Best Regards

 

This message was sent by Atlassian Jira (v7.13.6#713006-sha1:cc4451f)
Atlassian logo

jielpe-cblv38@protonmail.com (JIRA)

unread,
Nov 6, 2019, 10:23:02 AM11/6/19
to jenkinsc...@googlegroups.com
jlpinardon edited a comment on Bug JENKINS-57765
Hello,

Well, I really don't understand how you can consider this as not problematic.
It is really a pain indeed !

Let's consider a user who wants to make some quick trials, or even a user who tries to avoid using a shell step with some more or less complex script to simply test a ssh connection. He finds the sshCommand and thinks ok, great ! I found what I need ! I have a simple way of testing, enclosing the sshCommand within a try / catch and calling a simple uname or ls command.
... But he is totally disappointed because ... ok, there is no problem. It seems to work, but he is not sure because he has no output. And he need the output fir this or that reason because he wants to check something.

That's my use case... even worst in fact. Because my organisation wants to set a bunch of test cases to validate the ssh step in order to be sure it can be used it in production, and later on to have some regression tests when upgrading jenkins and plugins. And at the first trial, I fall into this trap.

_How can I say to people supporting Jenkins... hey men, that's OK. It works as a charm and everybody can use it with no worries !_


So, no, it is not a cosmetic problem. It is a real one because it is more or less related to some unpredictable response time. I am not sure if 5 sec is enough. Perhaps it is less (and I loose time) perhaps it is more, and I both loose information and fail a test which is actually a success.

Besides, it transfers the responsibility of ensuring the complete achievement of the step to the caller. I cannot really consider this as a normal situation.

So, please, could you consider again this as bug to fix ?

Thanks for your help.
Best Regards

 

naresh.rayapati@gmail.com (JIRA)

unread,
Nov 6, 2019, 11:53:03 AM11/6/19
to jenkinsc...@googlegroups.com

jlpinardon Thank you for the feedback.

JENKINS-59781 There is another JIRA logged for this problem, I am suggesting the same solution over there too, and I tried a couple of options and so far no luck. I will post more details on that JIRA once I know some good news. you are welcome to help if you would like to, please.

I can add sleep to the code inside the step but that would delay the entire pipeline execution a lot when the actual pipeline is using this step several times, is the reason I am suggesting it as a hacky solution to users for now.

There are a bunch of ways how we can test Jenkins pipelines in general, but what we do at our organization is we write unit test cases using https://github.com/homeaway/jenkins-spock and also we have test pipeline jobs with several use cases to regression test few of these important plugins.

And I doubt if I have answers to your other general questions except I trust Jenkins cause it gives me the flexibility/pride that I am a Developer. Thanks again.

christian.ciach@gmail.com (JIRA)

unread,
Mar 31, 2020, 12:21:03 PM3/31/20
to jenkinsc...@googlegroups.com

I, too, see the issue with the highly asynchronous log output of this plugin. Even status logging (like "Executing command on name[server]: mycommand sudo: false")  is highly out of sync to the rest of the log (and sometimes doesn't get logged at all), making the log very confusing to read.

Looking at the code, it looks to me like the likely issue is a missing flush()-call to the CustomLogHandler (or maybe the rootLogger) at the end of this method: https://github.com/jenkinsci/ssh-steps-plugin/blob/c35e7db86e975b257343179fd4f08dd0af8cbb42/src/main/groovy/org/jenkinsci/plugins/sshsteps/SSHService.groovy#L55

That being said.. Is it really a good Idea to register a new CustomLogHandler every time something gets logged?

This message was sent by Atlassian Jira (v7.13.12#713012-sha1:6e07c38)
Atlassian logo

christian.ciach@gmail.com (JIRA)

unread,
Mar 31, 2020, 12:24:03 PM3/31/20
to jenkinsc...@googlegroups.com
Christian Ciach edited a comment on Bug JENKINS-57765
I, too, see the issue with the highly asynchronous log output of this plugin. Even status logging ( like for example: "{{Executing command on name[server]: mycommand sudo: false"}})  is highly out of sync to the rest of the log (and sometimes doesn't get logged at all), making the log very confusing to read.


Looking at the code, it looks to me like the likely issue is a missing flush()-call to the CustomLogHandler (or maybe the rootLogger) at the end of this method: [https://github.com/jenkinsci/ssh-steps-plugin/blob/c35e7db86e975b257343179fd4f08dd0af8cbb42/src/main/groovy/org/jenkinsci/plugins/sshsteps/SSHService.groovy#L55]

That being said.. Is it really a good Idea to register a new CustomLogHandler every time something gets logged?

christian.ciach@gmail.com (JIRA)

unread,
Mar 31, 2020, 12:26:04 PM3/31/20
to jenkinsc...@googlegroups.com
Christian Ciach edited a comment on Bug JENKINS-57765
I, too, see the issue with the highly asynchronous log output of this plugin. Even status logging (for example: "{{Executing command on name[server]: mycommand sudo: false"}})  is highly out of sync to the rest of the log (and sometimes doesn't get logged at all), making the log very confusing to read. This is an issue with this plugin, because these messages are written by the plugin itself. This doesn't have anything to do with the underlying groovy-ssh library.

Looking at the code, it looks to me like the likely issue is a missing flush()-call to the CustomLogHandler (or maybe the rootLogger) at the end of this method: [https://github.com/jenkinsci/ssh-steps-plugin/blob/c35e7db86e975b257343179fd4f08dd0af8cbb42/src/main/groovy/org/jenkinsci/plugins/sshsteps/SSHService.groovy#L55]

That being said.. Is it really a good Idea to register a new CustomLogHandler every time something gets logged?

christian.ciach@gmail.com (JIRA)

unread,
Mar 31, 2020, 12:27:02 PM3/31/20
to jenkinsc...@googlegroups.com
Christian Ciach edited a comment on Bug JENKINS-57765
I, too, see the issue with the highly asynchronous log output of this plugin. Even status logging (for example: "{{Executing command on name[server]: mycommand sudo: false"}})  is highly out of sync to the rest of the log (and sometimes doesn't get logged at all), making the log very confusing to read. This is an issue with this plugin, because these messages are written by the plugin itself. This doesn't have anything to do with the underlying groovy-ssh library.

Looking at the code, it looks seems to me like that the likely issue is a missing flush()-call to the CustomLogHandler (or maybe the rootLogger) at the end of this method: [https://github.com/jenkinsci/ssh-steps-plugin/blob/c35e7db86e975b257343179fd4f08dd0af8cbb42/src/main/groovy/org/jenkinsci/plugins/sshsteps/SSHService.groovy#L55]


That being said.. Is it really a good Idea to register a new CustomLogHandler every time something gets logged?

christian.ciach@gmail.com (JIRA)

unread,
Mar 31, 2020, 12:51:10 PM3/31/20
to jenkinsc...@googlegroups.com
Christian Ciach edited a comment on Bug JENKINS-57765
I, too, see the issue with the highly asynchronous log output of this plugin. Even status logging (for example: "{{Executing command on name[server]: mycommand sudo: false"}})  is highly out of sync to the rest of the log (and sometimes doesn't get logged at all), making the log very confusing to read. This is an issue with this plugin, because these messages are written by the plugin itself. This doesn't have anything to do with the underlying groovy-ssh library.

Looking at the code, it seems to me that the likely issue is a missing flush()-call to the CustomLogHandler (or maybe the rootLogger) at the end of this method: [https://github.com/jenkinsci/ssh-steps-plugin/blob/c35e7db86e975b257343179fd4f08dd0af8cbb42/src/main/groovy/org/jenkinsci/plugins/sshsteps/SSHService.groovy#L55]

That being said.. Is it really a good Idea to register a new CustomLogHandler every time something gets logged?
The rootLogger is most likely static, so adding new handlers for each and every message will eventually lead to a ton of CustomLogHandlers that are probably never garbage collected.
Reply all
Reply to author
Forward
0 new messages