Every SSH connection logs mux_client_read_packet: read header failed: Broken pipe

[John Bateman]

Each SSH connection throughout every playbook execution ends with Broken Pipe error message mux_client_read_packet: read header failed: Broken pipe, seen with verbose logging enabled. This doesn't cause the failure of a task and the connection can still be seen to return a 0 exit code and the playbook executes successfully. I'm not getting any performance improvements with pipelining enabled and I am curious if this would have a performance impact on ControlPersist and pipelining if connections are terminating like this?

Full debug output here: https://gist.github.com/johnbateman/c2257c750798d1f48adc95deb66e3b61#file-gistfile1-txt

ansible 2.9.4
  config file = /etc/ansible/ansible.cfg
  configured module search path = [u'/home/vagrant/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/lib/python2.7/site-packages/ansible
  executable location = /usr/bin/ansible
  python version = 2.7.5 (default, Aug  7 2019, 00:51:29) [GCC 4.8.5 20150623 (Red Hat 4.8.5-39)]

[John Bateman]

Does anyone have any ideas on this. Can anyone else verify the same behaviour?

[James Cassell]

On Mon, Feb 24, 2020, at 9:01 PM, John Bateman wrote:
> Each SSH connection throughout every playbook execution ends with
> Broken Pipe error message `mux_client_read_packet: read header failed:

> Broken pipe`, seen with verbose logging enabled. This doesn't cause the

> failure of a task and the connection can still be seen to return a 0
> exit code and the playbook executes successfully. I'm not getting any
> performance improvements with pipelining enabled and I am curious if
> this would have a performance impact on ControlPersist and pipelining
> if connections are terminating like this?
>
>
>
> Full debug output here:
> https://gist.github.com/johnbateman/c2257c750798d1f48adc95deb66e3b61#file-gistfile1-txt
>
>

Maybe try just 3 v's... I got lost in the output.

V/r
James Cassell


>
> `
> `ansible 2.9.4

>   config file = /etc/ansible/ansible.cfg
>   configured module search path =
> [u'/home/vagrant/.ansible/plugins/modules',
> u'/usr/share/ansible/plugins/modules']
>   ansible python module location =
> /usr/lib/python2.7/site-packages/ansible
>   executable location = /usr/bin/ansible
>   python version = 2.7.5 (default, Aug  7 2019, 00:51:29) [GCC 4.8.5

> 20150623 (Red Hat 4.8.5-39)]`
> `
>

[Mark Hansen]

I'm also observing this problem too.

ansible-playbook 2.9.5

  config file = /Users/mark/projects/pis/ansible.cfg

  configured module search path = ['/Users/mark/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']

  ansible python module location = /Users/mark/Library/Python/3.7/lib/python/site-packages/ansible

  executable location = /Users/mark/Library/Python/3.7/bin/ansible-playbook

  python version = 3.7.6 (default, Dec 30 2019, 19:38:26) [Clang 11.0.0 (clang-1100.0.33.16)]

Every task execution notes in the logs

debug3: mux_client_read_packet: read header failed: Broken pipe

[Mark Hansen]

Oh, and here's my ansible.cfg

> cat ansible.cfg

[ssh_connection]

pipelining = True

# ssh_args = -C -o ControlMaster=auto -o ControlPersist=30m

# https://github.com/ansible/ansible/issues/26359

[defaults]

# Defaults to /usr/bin/python otherwise

interpreter_python = /usr/bin/python3

# https://sketchingdev.co.uk/blog/profiling-ansible-playbooks-to-csv.html

callback_whitelist = profile_tasks

[Mark Hansen]

I'm investigating a bit further, I see the SSH command that ansible is executing (look for the line starting with "SSH: EXEC", and I try running that in isolation:

ssh -vvv -C -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="pi"' -o ConnectTimeout=10 -o ControlPath=/Users/mark/.ansible/cp/c4fffefc6d pi4b '/bin/sh -c "/usr/bin/python3 && sleep 0"'

Then the shell will hang waiting for you to enter a python command (it's running /usr/bin/python3). you can type print("hello") to see this - it prints "hello".

print('hello')

^D (eof)
hello

debug3: mux_client_read_packet: read header failed: Broken pipe

debug2: Received exit status from master 0

If I run this in multiple terminals, I can see that the error "debug3: mux_client_read_packet: read header failed: Broken pipe" is an error being printed by SSH, not by ansible itself.

It also appears that SSH is actually reusing the multiplexed connection - if I run this command from multiple terminals, the first terminal shows status messages about the connection for the other terminals.

--
You received this message because you are subscribed to a topic in the Google Groups "Ansible Project" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/ansible-project/m-AB1PbMNaM/unsubscribe.
To unsubscribe from this group and all its topics, send an email to ansible-proje...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/ansible-project/8b564a5a-8fbc-4207-b55e-382859c9f2f1%40googlegroups.com.

[Mark Hansen]

I tried taking a packet capture with Wireshark just to be double-sure that Ansible was reusing the same connection, and Ansible was.

I ran wireshark, limited capture to "tcp.port == 22", and then went to Menu -> Statistics -> Conversations -> TCP, and I observe only one long-lived TCP SSH connection per host.

Which is to say, I don't think this "broken pipe" error is breaking connection pooling.