Python Paramiko channel.exec_command not returning output intermittently

Question

I have a intermittent issue with execute remote operations using Paramiko.

if channel.active:
    contents = io.StringIO()
    error = io.StringIO()
    try:
        LOG.info('{} - Executing script {}  - as {} user '.format(self.target_host, script, self.targetvmuser))
        channel.exec_command(script)
        while not channel.exit_status_ready():
            if channel.recv_ready():
                data = channel.recv(1024)
                LOG.debug(data.decode())
                while data:
                    contents.write(data.decode())
                    data = channel.recv(1024)
                    LOG.debug(data.decode())
            if channel.recv_stderr_ready():
                error_buff = channel.recv_stderr(1024)
                LOG.debug(error_buff.decode())
                while error_buff:
                    error.write(error_buff.decode())
                    error_buff = channel.recv_stderr(1024)
                    LOG.debug(error_buff.decode())
        exit_status = channel.recv_exit_status()

Below are the debug logs of 2 executions. I am not able to figure out why the output below is returned on one VM but not on another VM.

2022-03-17 12:14:42 [DEBUG] - -rw-rw-r--. 1  test test 1702 Mar 17 12:14 /tmp/testfile

2022-03-17 12:14:42 [DEBUG] -

Linux VM with Paramiko 2.7.2 - intermittent Bad run.

2022-03-17 12:14:20 [DEBUG][chan 0] Max packet out: 32768 bytes
2022-03-17 12:14:20 [DEBUG] - Secsh channel 0 opened.
2022-03-17 12:14:20 [DEBUG] - [chan 1] Max packet in: 32768 bytes
2022-03-17 12:14:20 [DEBUG] - [chan 1] Max packet out: 32768 bytes
2022-03-17 12:14:20 [DEBUG] - Secsh channel 1 opened.
2022-03-17 12:14:20 [DEBUG] - [chan 1] Sesch channel 1 request ok
2022-03-17 12:14:20 [INFO ] - [chan 1] Opened sftp connection (server version 3)
2022-03-17 12:14:20 [DEBUG] - [chan 1] open(b'/tmp/testfile', 'wb')
2022-03-17 12:14:20 [DEBUG] - Sending global request "[email protected]"
2022-03-17 12:14:20 [DEBUG] - [chan 1] open(b'/tmp/testfile', 'wb') -> 00000000
2022-03-17 12:14:20 [DEBUG] - [chan 1] close(00000000)
2022-03-17 12:14:20 [DEBUG] - [chan 1] stat(b'/tmp/testfile')
2022-03-17 12:14:20 [DEBUG] - [chan 2] Max packet in: 32768 bytes
2022-03-17 12:14:20 [DEBUG] - [chan 2] Max packet out: 32768 bytes
2022-03-17 12:14:20 [DEBUG] - Secsh channel 2 opened.
2022-03-17 12:14:20 [INFO ] - 10.9.59.11 - Executing script ls -ltr /tmp/testfile  - as opc user 
2022-03-17 12:14:20 [DEBUG] - [chan 2] Sesch channel 2 request ok
2022-03-17 12:14:20 [DEBUG] - Sending global request "[email protected]"
2022-03-17 12:14:20 [DEBUG] - Sending global request "[email protected]"
2022-03-17 12:14:20 [DEBUG] - [chan 2] EOF received (2)
2022-03-17 12:14:20 [DEBUG] - [chan 2] EOF sent (2)
2022-03-17 12:14:20 [INFO ] - 10.9.59.11 -script ls -ltr /tmp/testfile 0 - exit code is 0
2022-03-17 12:14:20 [INFO ] - [chan 1] sftp session closed.
2022-03-17 12:14:20 [DEBUG] - [chan 1] EOF sent (1)
2022-03-17 12:14:20 [DEBUG] - [chan 0] EOF sent (0)
2022-03-17 12:14:20 [DEBUG] - [chan 0] EOF sent (0)
2022-03-17 12:14:20 [DEBUG] - EOF in transport thread

Linux VM with Paramiko 2.9.2 & Windows – Paramiko 2.7.2 – No issues – Always Good Run.

2022-03-17 12:14:42 [DEBUG] - [chan 0] Max packet out: 32768 bytes
2022-03-17 12:14:42 [DEBUG] - Secsh channel 0 opened.
2022-03-17 12:14:42 [DEBUG] - [chan 1] Max packet in: 32768 bytes
2022-03-17 12:14:42 [DEBUG] - [chan 1] Max packet out: 32768 bytes
2022-03-17 12:14:42 [DEBUG] - Secsh channel 1 opened.
2022-03-17 12:14:42 [DEBUG] - [chan 1] Sesch channel 1 request ok
2022-03-17 12:14:42 [DEBUG] - Sending global request "[email protected]"
2022-03-17 12:14:42 [INFO ] - [chan 1] Opened sftp connection (server version 3)
2022-03-17 12:14:42 [DEBUG] - [chan 1] open(b'/tmp/testfile', 'wb')
2022-03-17 12:14:42 [DEBUG] - [chan 1] open(b'/tmp/testfile', 'wb') -> 00000000
2022-03-17 12:14:42 [DEBUG] - [chan 1] close(00000000)
2022-03-17 12:14:42 [DEBUG] - Sending global request "[email protected]"
2022-03-17 12:14:42 [DEBUG] - [chan 1] stat(b'/tmp/testfile')
2022-03-17 12:14:42 [DEBUG] - [chan 2] Max packet in: 32768 bytes
2022-03-17 12:14:42 [DEBUG] - Sending global request "[email protected]"
2022-03-17 12:14:42 [DEBUG] - [chan 2] Max packet out: 32768 bytes
2022-03-17 12:14:42 [DEBUG] - Secsh channel 2 opened.
2022-03-17 12:14:42 [INFO ] - 10.9.59.11 - Executing script ls -ltr /tmp/testfile  - as test user 
2022-03-17 12:14:42 [DEBUG] - Sending global request "[email protected]"
2022-03-17 12:14:42 [DEBUG] - [chan 2] Sesch channel 2 request ok
2022-03-17 12:14:42 [DEBUG] - [chan 2] EOF received (2)
2022-03-17 12:14:42 [DEBUG] - [chan 2] EOF sent (2)
2022-03-17 12:14:42 [DEBUG] - -rw-rw-r--. 1  test test 1702 Mar 17 12:14 /tmp/testfile
2022-03-17 12:14:42 [DEBUG] - 
2022-03-17 12:14:42 [INFO ] - 10.9.59.11 -script ls -ltr /tmp/testfile 0 - exit code is 0
2022-03-17 12:14:42 [INFO ] - [chan 1] sftp session closed.
2022-03-17 12:14:42 [DEBUG] - [chan 1] EOF sent (1)
2022-03-17 12:14:42 [DEBUG] - [chan 0] EOF sent (0)
2022-03-17 12:14:42 [DEBUG] - [chan 0] EOF sent (0)
2022-03-17 12:14:42 [DEBUG] - EOF in transport thread

Martin Prikryl · Accepted Answer · 2024-10-10 13:01:47Z

1

It's probably a race condition. The exit_status_ready can return true if the command has finished, even if you have not read its complete output yet.

The correct code is like:

while True:
    exited = channel.exit_status_ready()
    if channel.recv_ready():
        data = channel.recv(1024)
        LOG.debug(data.decode())
        while data:
            contents.write(data.decode())
            data = channel.recv(1024)
            LOG.debug(data.decode())
    if channel.recv_stderr_ready():
        error_buff = channel.recv_stderr(1024)
        LOG.debug(error_buff.decode())
        while error_buff:
            error.write(error_buff.decode())
            error_buff = channel.recv_stderr(1024)
            LOG.debug(error_buff.decode())
    if exited:
        break

I.e. to check exit_status_ready before reading the output, but act upon it only afterwards.

edited Oct 10, 2024 at 13:01

answered Mar 17, 2022 at 18:05

Martin Prikryl

205k64 gold badges560 silver badges1.1k bronze badges

Sign up to request clarification or add additional context in comments.

Collectives™ on Stack Overflow

Python Paramiko channel.exec_command not returning output intermittently

1 Answer 1

Comments

Your Answer

Linked

Hot Network Questions

Collectives™ on Stack Overflow

1 Answer 1

Comments

Your Answer

Sign up or log in

Post as a guest

Linked

Related