Mitogen + sudo + log_stdin/log_stdout leads to preamble read error in first stage (EAGAIN, EWOULDBLOCK, None)

[moreati]

Under certain conditions (e.g. sudo with the log_input or log_output flag) the stdin of Mitogen's first stage can be set non-blocking (O_NONBLOCK) this results in fp.read() returning None if the buffer is empty.

The error seen by the user looks like

MITO000
Traceback … TypeError: a bytes-like object is required, not 'NoneType'

This may be related to #712, #1185.

Credit to @Forgetyk for the original error and diagnosis, their words follow.

Environment

Component	Version
OS	Linux 5247089-it57222 5.15.0-142-generic #152-Ubuntu SMP Mon May 19 10:54:31 UTC 2025 x86_64 x86_64 x86_64 x86_64 GNU/Linux
Python	3.10.12
sudo	1.9.9
OpenSSH	OpenSSH_8.9p1 Ubuntu-3ubuntu0.10,
ansible-core	2.12.10

All tests were run with strategy = mitogen_linear and pipelining = true.

Reproducer

1. Target host – enable sudo I/O logging:

   # /etc/sudoers
   Defaults log_output
   Defaults!/usr/bin/sudoreplay !log_output
   Defaults!/usr/local/bin/sudoreplay !log_output
   Defaults!/sbin/reboot !log_output
   Defaults loglinelen=0
   Defaults logfile=/var/log/sudo.log
   #Defaults:ansible !log_output, !log_input
   root    ALL=(ALL:ALL) ALL
   %admin ALL=(ALL) ALL
   %sudo   ALL=(ALL:ALL) ALL
   @includedir /etc/sudoers.d
   

2. Target host – ssh settings:

   # /etc/ssh/sshd_config
   Protocol 2
   SyslogFacility AUTH
   LogLevel INFO
   LoginGraceTime 60
   PermitRootLogin no
   PermitEmptyPasswords no
   IgnoreRhosts yes
   HostbasedAuthentication no
   X11Forwarding no
   ClientAliveInterval 900
   ClientAliveCountMax 0
   AllowTcpForwarding no
   ChallengeResponseAuthentication no
   UsePAM yes
   Subsystem    sftp    /usr/lib/openssh/sftp-server
   PrintMotd no
   ListenAddress 0.0.0.
   

3. Controller – standard Mitogen config (only the interesting bits):

   # ansible.cfg
   [defaults]
   strategy_plugins = /…/ansible_mitogen/plugins/strategy
   strategy         = mitogen_linear
   [ssh_connection]
   pipelining = true

4. Inventory

   [target]
   iac-test-2 ansible_user=ansible ansible_python_interpreter=/usr/bin/python3

5. Playbook

    become: yes
    gather_facts: no
    hosts:
      - iac-test-2
    roles:
      - some_role
    vars:
      some_var: "{{ var }}"

6. Result

   BlockingIOError: [Errno 35] Resource temporarily unavailable
   mitogen.core.py", line 2247, in write
   

   The crash appears within a few hundred ms, long before any module code is executed.

What is happening

• sudo log_output/log_input spawns a pseudo‑terminal in front of the command it runs and copies all I/O through that PTY.
  The PTY’s kernel buffer is only ~64 KiB.
• Mitogen opens both ends of its pipes O_NONBLOCK and uses an event loop.
• During the bootstrap it pushes ~35 KiB of compressed preamble in one go; a couple of other writes follow immediately.
  When the PTY buffer fills up, write() returns EAGAIN → BlockingIOError, which is not retried and kills the stream.

Plain Ansible (no Mitogen) performs the same copy through sudo, but its os.write() is blocking, so it simply waits and survives.

Work‑around that mask the issue

Defaults:ansible !log_output, !log_input might be a solution for other similar problems, but it is forbidden within our production regulations.

Because disabling I/O logging is off‑limits for compliance, we need Mitogen to gracefully retry EAGAIN (or temporarily switch to blocking writes).

-- Originally posted by @Forgetyk in #1299 (comment)

[moreati]

Some background digging

use_pty

If set, and sudo is running in a terminal, the command will be run in a pseudo-terminal (even if no I/O logging is being done). If the sudo process is not attached to a terminal, use_pty has no effect.

-- https://manpages.debian.org/bookworm/sudo/sudoers.5.en.html#SUDOERS_OPTIONS

When I/O logging is enabled, sudo will runs the command in a pseudo-terminal,
logging user input and/or output, depending on which sudoers flags are
enabled. There are five distinct types of I/O that can be logged, each with a
corresponding sudoers flag.

Type	Flag	Description
terminal input	log_ttyin	keystrokes entered by the user
terminal output	log_ttyout	command output displayed to the screen
standard input	log_stdin	input from a pipe or a file
standard output	log_stdout	output to a pipe or a file
standard error	log_stderr	output to a pipe or a file

In addition to flags described the above, the log_input flag and LOG_INPUT
command tag set both log_ttyin and log_stdin. The log_output flag and
LOG_OUTPUT command tag set log_ttyout, log_stdout, and log_stderr.
-- https://manpages.debian.org/bookworm/sudo/sudoers.5.en.html#I/O_LOGGING

Rough history of changes

• Sudo 1.7.3
  • Added use_pty
    (Jun 2010, https://git.sudo.ws/sudo/commit/?id=6f05b565c)
  • Seperated older transcript feature to log_input and log_output
    (May 2010, https://git.sudo.ws/sudo/commit/?id=2dd29bf64)
• Sudo 1.8.20
  • Restricted interposing to when log_input is enabled
    (May 2017, https://git.sudo.ws/sudo/commit/?id=44dc15d02)
• Sudo 1.9.12
  • Introudced log_std* and log_tty*
    (Sep 2022, https://git.sudo.ws/sudo/commit/?id=ce387a684)

Refs

• https://www.sudo.ws/releases/legacy/
• https://www.sudo.ws/releases/stable/
• https://www.sudo.ws/releases/changelog/

[moreati]

Failed to replicate using Ubuntu 22.04 VM

alex@ubuntu2004:~/src/mitogen$ .venv/bin/ansible-playbook issue1306_repro.yml
[WARNING]: No inventory was parsed, only implicit localhost is available
[WARNING]: provided hosts list is empty, only localhost is available. Note that the implicit localhost does not match 'all'
  
PLAY [localhost] *********************************************************************************************************************************************
  
TASK [command] ***********************************************************************************************************************************************
changed: [localhost]
  
PLAY RECAP ***************************************************************************************************************************************************
localhost                  : ok=1    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0  

# issue1306_repro.yml
- hosts: localhost
  connection: ssh
  become: true
  gather_facts: false
  vars:
    ansible_become_password: fred
  tasks:
    - command: echo hello

# ansible.cfg
[defaults]
strategy_plugins = ansible_mitogen/plugins/strategy
strategy = mitogen_linear
  
[ssh_connection]
pipelining = true

alex@ubuntu2004:~/src/mitogen$ .venv/bin/ansible --version
ansible [core 2.12.10]
  config file = /home/alex/src/mitogen/ansible.cfg
  configured module search path = ['/home/alex/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/alex/src/mitogen/.venv/lib/python3.10/site-packages/ansible
  ansible collection location = /home/alex/.ansible/collections:/usr/share/ansible/collections
  executable location = .venv/bin/ansible
  python version = 3.10.12 (main, May 27 2025, 17:12:29) [GCC 11.4.0]
  jinja version = 3.1.6
  libyaml = True
alex@ubuntu2004:~/src/mitogen$ sudo egrep '^Defaults.+(log_|use_)' /etc/sudoers
Defaults        log_input
Defaults        log_output
Defaults        use_pty
alex@ubuntu2004:~/src/mitogen$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 22.04.5 LTS
Release:        22.04
Codename:       jammy

alex@ubuntu2004:~/src/mitogen$ git diff
diff --git a/mitogen/parent.py b/mitogen/parent.py
index 7c56c734..f36bba89 100644
--- a/mitogen/parent.py
+++ b/mitogen/parent.py
@@ -1422,6 +1422,7 @@ class Connection(object):
     # "[1234 refs]" during exit.
     @staticmethod
     def _first_stage():
+        import fcntl
         R,W=os.pipe()
         r,w=os.pipe()
         if os.fork():
@@ -1438,6 +1439,7 @@ class Connection(object):
             os.execl(sys.executable,sys.executable+'(mitogen:CONTEXT_NAME)')
         os.write(1,'MITO000\n'.encode())
         fp=os.fdopen(0,'rb')
+        assert not (fcntl.fcntl(fp.fileno(), fcntl.F_GETFL) & os.O_NONBLOCK)
         C=zlib.decompress(fp.read(PREAMBLE_COMPRESSED_LEN))
         fp.close()
         fp=os.fdopen(W,'wb',0)

[moreati]

I didn't add "Defaults use_pty" to /etc/sudoers. It was already there, I think it's a distro default.

[moreati]

Also negative repro using Mitogen 0.3.24

alex@ubuntu2004:~/src/issue1306$ .venv/bin/ansible-playbook issue1306_repro.yml 
[WARNING]: No inventory was parsed, only implicit localhost is available
[WARNING]: provided hosts list is empty, only localhost is available. Note that the implicit localhost does not match 'all'

PLAY [localhost] *********************************************************************************************************************************************

TASK [command] ***********************************************************************************************************************************************
changed: [localhost]

PLAY RECAP ***************************************************************************************************************************************************
localhost                  : ok=1    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0   

# ansible.cfg 
[defaults]
strategy_plugins = .venv/lib/python3.10/site-packages/ansible_mitogen/plugins/strategy
strategy = mitogen_linear

[ssh_connection]
pipelining = true

[Forgetyk]

I just showed in my environment that this parameter is not there Defaults use_pty. It should be commented out.

[moreati]

Defaults use_pty. It should be commented out.

Commenting it out didn't make any difference. I've since confiurmed "Default use_pty" is present out the box on freshly installed Ubuntu 22.04.

I mentioned it because the man page descriptions of "log_input", "log_output", and "use_pty" all mention running the command with a pseudo-terminal (pty) when enabled. If Default use_pty is a common case, then that may be evidence against log_input and/or log_output being a sufficient condition to trigger this bug.

alex@ubuntu2004:~/src/issue1306$ .venv/bin/ansible-playbook issue1306_repro.yml 
[WARNING]: No inventory was parsed, only implicit localhost is available
[WARNING]: provided hosts list is empty, only localhost is available. Note that the implicit localhost does not match 'all'

PLAY [localhost] *********************************************************************************************************************************************

TASK [command] ***********************************************************************************************************************************************
changed: [localhost]

PLAY RECAP ***************************************************************************************************************************************************
localhost                  : ok=1    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0   

alex@ubuntu2004:~/src/issue1306$ sudo egrep '^Defaults' /etc/sudoers
Defaults	log_input
Defaults	log_output
Defaults	env_reset
Defaults	mail_badpass
Defaults	secure_path="/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin"

[moreati]

I just notice we have 2 different errors

1. fp.read(PREAMBLE_COMPRESSED_LEN) returns None, leading to zlib.decompress() raising

   Traceback … TypeError: a bytes-like object is required, not 'NoneType'"

   This is error is first reported in the description of PR Read all preamble without PREAMBLE_COMPRESSED_LEN in first stage? #1305

2. fp.write(C) A call to os.write() in mitogen.core raises

   BlockingIOError: [Errno 35] Resource temporarily unavailable
   mitogen.core.py", line 2247, in write

   This error is reported in parent: avoid early-EOF in sudo bootstrap, wait until full preamble is read #1299 (comment), that first mentions log_input/log_output.

[moreati]

I just notice we have 2 different errors

Error 2 (BlockingIOError in core.py, line 2247) looks a lot more like #1185.

[moreati]

Finally manged to reproduce this

alex@u2204arm:~/src/mitogen$ python3 issue1305.py --sudo 1000
Traceback (most recent call last):
  File "/home/alex/src/mitogen/issue1305.py", line 12, in <module>
    def main(router):
  File "/home/alex/src/mitogen/mitogen/__init__.py", line 115, in wrapper
    return mitogen.core._profile_hook(
  File "/home/alex/src/mitogen/mitogen/core.py", line 676, in _profile_hook
    return func(*args)
  File "/home/alex/src/mitogen/mitogen/utils.py", line 151, in run_with_router
    return func(router, *args, **kwargs)
  File "/home/alex/src/mitogen/issue1305.py", line 24, in main
    ctx = router.sudo(via=ctx, password=args.sudo_password, python_path='python3')
  File "/home/alex/src/mitogen/mitogen/parent.py", line 2505, in sudo
    return self.connect(u'sudo', **kwargs)
  File "/home/alex/src/mitogen/mitogen/parent.py", line 2450, in connect
    return self._connect(klass, **mitogen.core.Kwargs(kwargs))
  File "/home/alex/src/mitogen/mitogen/parent.py", line 2430, in _connect
    conn.connect(context=context)
  File "/home/alex/src/mitogen/mitogen/parent.py", line 1712, in connect
    raise self.exception
mitogen.parent.EofError: EOF on stream; last 100 lines received:
[sudo] password for alex:
MITO000
Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "<string>", line 17, in <module>
TypeError: a bytes-like object is required, not 'NoneType'

import argparse
import os
import sys

import mitogen

def shout(size):
    nwritten = sys.stdout.write('A'*size)
    return nwritten

@mitogen.main()
def main(router):
    parser = argparse.ArgumentParser()
    parser.add_argument('--ssh', action='store_true')
    parser.add_argument('--sudo', action='store_true')
    parser.add_argument('--sudo-password', default='fred')
    parser.add_argument('size', type=int)
    args = parser.parse_args()
    if args.ssh:
        ctx = router.ssh(hostname='localhost', python_path='python3')
    else:
        ctx = None
    if args.sudo:
        ctx = router.sudo(via=ctx, password=args.sudo_password, python_path='python3')

    print(ctx.call(shout, args.size))

alex@u2204arm:~/src/mitogen$ sudo head -n20 /etc/sudoers
#
# This file MUST be edited with the 'visudo' command as root.
#
# Please consider adding local content in /etc/sudoers.d/ instead of
# directly modifying this file.
#
# See the man page for details on how to write a sudoers file.
#
Defaults        env_reset
Defaults        mail_badpass
Defaults        secure_path="/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin"
Defaults        use_pty

Defaults log_output
#Defaults loglinelen=0
#Defaults logfile=/var/log/sudo.log

# This preserves proxy settings from user environments of root
# equivalent users (group sudo)
#Defaults:%sudo env_keep += "http_proxy https_proxy ftp_proxy all_proxy no_proxy"

[moreati]

With

diff --git a/mitogen/parent.py b/mitogen/parent.py
index 7ac14fb1..77e8f4fa 100644
--- a/mitogen/parent.py
+++ b/mitogen/parent.py
@@ -1441,6 +1441,7 @@ class Connection(object):
             os.execl(sys.executable,sys.executable+'(mitogen:CONTEXT_NAME)')
         os.write(1,'MITO000\n'.encode())
         fp=os.fdopen(0,'rb')
+        import fcntl; assert not (fcntl.fcntl(fp, fcntl.F_GETFL) & os.O_NONBLOCK)
         C=zlib.decompress(fp.read(PREAMBLE_COMPRESSED_LEN))
         fp.close()
         fp=os.fdopen(W,'wb',0)

the Error changes to

alex@u2204arm:~/src/mitogen$ python3 issue1305.py --sudo 1000
...
mitogen.parent.EofError: EOF on stream; last 100 lines received:
[sudo] password for alex:
MITO000
Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "<string>", line 18, in <module>
AssertionError

so stdin (fd=0) is non-blocking when /etc/sudoers sets "Defaults log_output". Commenting out that line in /etc/sudoers causes the assert to pass

alex@u2204arm:~/src/mitogen$ sudo grep log_output /etc/sudoers
#Defaults log_output
alex@u2204arm:~/src/mitogen$ python3 issue1305.py --sudo 1000
1000

So I'm tentatively concluding that sudo (or atleast the combination sudo+mitogen) is causing fd=0 to be non-blocking. It's not mitogen doing it.

Edit: sudo 1.9.9 on Ubuntu 22.04.5 (jammy), aarch64

[moreati]

Same with sudo 1.9.15p5 on Ubuntu 24.0.4.3 (noble), aarch64

alex@u2404arm:~/src/mitogen$ sudo grep -C1 log_output /etc/sudoers
Defaults        use_pty
Defaults        log_output

alex@u2404arm:~/src/mitogen$ python3 issue1305.py
...
mitogen.parent.EofError: EOF on stream; last 100 lines received:
[sudo] password for alex:
MITO000
Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "<string>", line 17, in <module>
AssertionError

[moreati]

Same with sudo 1.9.16p2 on Debian 13.0, aarch64

alex@d13arm:~/src/mitogen$ python3 --version
Python 3.13.5
alex@d13arm:~/src/mitogen$ sudo grep -C1 log_output /etc/sudoers
Defaults        use_pty
Defaults        log_output
 
alex@d13arm:~/src/mitogen$ python3 issue1306.py
Traceback (most recent call last):
...
mitogen.parent.EofError: EOF on stream; last 100 lines received:
[sudo] password for alex:
MITO000
Traceback (most recent call last):
...
AssertionError