New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Key based SSH authentication does not work when switching to mitogen_linear #307

Closed
falbanese opened this Issue Jul 17, 2018 · 4 comments

Comments

Projects
None yet
2 participants
@falbanese

falbanese commented Jul 17, 2018

I have followed the installation steps and changed Ansible default strategy to mitogen_linear.
Unfortunately, mitogen assumes that each SSH connection asks for a password. E.g.:

[tpuser@localhost ~]$ ansible host01 -m ping
host01| UNREACHABLE! => {
    "changed": false,
    "msg": "SSH password was requested, but none specified",
    "unreachable": true
}

My user is setup to connect using SSH keys. Stock Ansible runs fine without specifying any additional SSH parameter.

The following is the command output using quadruple verbose logging:

tpusr@localhost:~> ansible host01 -vvvv -m ping
ansible 2.4.0.0
  config file = /home/tpusr/.ansible.cfg
  configured module search path = [u'/home/tpusr/.ansible/plugins/modules', u'/usr/share/ansible/plugins/modules']
  ansible python module location = /usr/lib/python2.7/site-packages/ansible
  executable location = /bin/ansible
  python version = 2.7.5 (default, May  3 2017, 07:55:04) [GCC 4.8.5 20150623 (Red Hat 4.8.5-14)]
Using /home/tpusr/.ansible.cfg as config file
setting up inventory plugins
Parsed /opt/ansible/inventory inventory source with ini plugin
Loading callback plugin minimal of type stdout, v2.0 from /usr/lib/python2.7/site-packages/ansible/plugins/callback/__init__.pyc
[pid 249226] 11:36:05.356054 D mitogen.io: Router(Broker(0x3a91990)).add_handler(<bound method IdAllocator.on_allocate_id of IdAllocator(Router(Broker(0x3a91990)))>, 105, True)
[pid 249226] 11:36:05.356925 D mitogen.io: Router(Broker(0x3a91990)).add_handler(<bound method ModuleResponder._on_get_module of ModuleResponder(Router(Broker(0x3a91990)))>, 100, True)
[pid 249226] 11:36:05.357203 D mitogen.io: Router(Broker(0x3a91990)).add_handler(<bound method LogForwarder._on_forward_log of LogForwarder(Router(Broker(0x3a91990)))>, 102, True)
[pid 249226] 11:36:05.357382 D mitogen.io: Router(Broker(0x3a91990)).add_handler(<bound method RouteMonitor._on_add_route of <mitogen.parent.RouteMonitor object at 0x3a89d10>>, 103, True)
[pid 249226] 11:36:05.357533 D mitogen.io: Router(Broker(0x3a91990)).add_handler(<bound method RouteMonitor._on_del_route of <mitogen.parent.RouteMonitor object at 0x3a89d10>>, 104, True)
[pid 249226] 11:36:05.357691 D mitogen.io: Router(Broker(0x3a91990)).add_handler(<bound method Router._on_detaching of Router(Broker(0x3a91990))>, 109, True)
[pid 249226] 11:36:05.358097 D mitogen.io: Broker(0x3a91990).start_receive(<mitogen.unix.Listener object at 0x3a91d50>)
[pid 249226] 11:36:05.358294 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).defer() [fd=11]
[pid 249226] 11:36:05.358613 D mitogen.io: Router(Broker(0x3a91990)).add_handler(<bound method Receiver._on_receive of Receiver(Router(Broker(0x3a91990)), 110)>, 110, True)
[pid 249226] 11:36:05.358665 D mitogen.io: EpollPoller(0x3a91bd0): POLLIN: 9
[pid 249226] 11:36:05.359569 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-0').get(timeout=None, block=True)
[pid 249226] 11:36:05.360003 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).on_receive()
[pid 249226] 11:36:05.360088 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-1').get(timeout=None, block=True)
[pid 249226] 11:36:05.360463 D mitogen.io: EpollPoller(0x3a91bd0).start_receive(13, (<Side of <mitogen.unix.Listener object at 0x3a91d50> fd 13>, <bound method Listener.on_receive of <mitogen.unix.Listener object at 0x3a91d50>>))
[pid 249226] 11:36:05.360731 D mitogen.io: EpollPoller(0x3a962d0).start_receive(14, None)
[pid 249226] 11:36:05.360921 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-2').get(timeout=None, block=True)
[pid 249226] 11:36:05.361035 D mitogen.io: EpollPoller(0x3a96ad0).start_receive(17, None)
[pid 249226] 11:36:05.361110 D mitogen.io: EpollPoller(0x3a91bd0)._control(13)
[pid 249226] 11:36:05.361269 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-3').get(timeout=None, block=True)
[pid 249226] 11:36:05.361858 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-4').get(timeout=None, block=True)
[pid 249226] 11:36:05.361941 D mitogen.io: EpollPoller(0x3a962d0)._control(14)
[pid 249226] 11:36:05.362539 D mitogen.io: EpollPoller(0x3a99150).start_receive(20, None)
[pid 249226] 11:36:05.362632 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-5').get(timeout=None, block=True)
[pid 249226] 11:36:05.362769 D mitogen.io: EpollPoller(0x3a96ad0)._control(17)
[pid 249226] 11:36:05.363290 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-6').get(timeout=None, block=True)
[pid 249226] 11:36:05.363683 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-7').get(timeout=None, block=True)
[pid 249226] 11:36:05.363222 D mitogen.io: Broker(0x3a91990)._loop_once(None, EpollPoller(0x3a91bd0))
[pid 249226] 11:36:05.364278 D mitogen.io: EpollPoller(0x3a89f90).start_receive(26, None)
[pid 249226] 11:36:05.367562 D mitogen: mitogen.service.Pool(0x3a96110, size=16, th='MainThread'): initialized
[pid 249226] 11:36:05.367878 D ansible_mitogen.process: Service pool configured: size=16
[pid 249226] 11:36:05.364360 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-9').get(timeout=None, block=True)
[pid 249226] 11:36:05.364420 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-8').get(timeout=None, block=True)
[pid 249226] 11:36:05.364587 D mitogen.io: EpollPoller(0x3a96e10).start_receive(23, None)
[pid 249226] 11:36:05.364654 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-0')._get_sleep(timeout=None, block=True, rfd=14, wfd=15)
META: ran handlers
[pid 249226] 11:36:05.364771 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-10').get(timeout=None, block=True)
[pid 249226] 11:36:05.365043 D mitogen.io: EpollPoller(0x3a99150)._control(20)
[pid 249226] 11:36:05.365416 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-11').get(timeout=None, block=True)
[pid 249226] 11:36:05.365709 D mitogen.io: EpollPoller(0x3a99c90).start_receive(29, None)
[pid 249226] 11:36:05.365888 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-1')._get_sleep(timeout=None, block=True, rfd=17, wfd=18)
[pid 249226] 11:36:05.366083 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-12').get(timeout=None, block=True)
[pid 249226] 11:36:05.366611 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-13').get(timeout=None, block=True)
[pid 249226] 11:36:05.366912 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-14').get(timeout=None, block=True)
[pid 249226] 11:36:05.367241 D mitogen.io: EpollPoller(0x3a9d690).start_receive(32, None)
[pid 249226] 11:36:05.367369 D mitogen.io: EpollPoller(0x3a9d6d0).start_receive(35, None)
[pid 249226] 11:36:05.367769 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-15').get(timeout=None, block=True)
[pid 249226] 11:36:05.368052 D mitogen.io: EpollPoller(0x3a89f90)._control(26)
[pid 249226] 11:36:05.368684 D mitogen.io: EpollPoller(0x3a99850).start_receive(38, None)
[pid 249226] 11:36:05.368754 D mitogen.io: EpollPoller(0x3a96710).start_receive(41, None)
[pid 249226] 11:36:05.368815 D mitogen.io: EpollPoller(0x3a96e10)._control(23)
[pid 249226] 11:36:05.369241 D mitogen.io: EpollPoller(0x3a99c10).start_receive(44, None)
[pid 249226] 11:36:05.369552 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-2')._get_sleep(timeout=None, block=True, rfd=20, wfd=21)
[pid 249226] 11:36:05.369820 D mitogen.io: EpollPoller(0x3a99c90)._control(29)
[pid 249226] 11:36:05.370002 D mitogen.io: EpollPoller(0x3a99810).start_receive(47, None)
[pid 249226] 11:36:05.370344 D mitogen.io: EpollPoller(0x3a99f90).start_receive(50, None)
[pid 249226] 11:36:05.370554 D mitogen.io: EpollPoller(0x3a99f50).start_receive(53, None)
[pid 249226] 11:36:05.370706 D mitogen.io: EpollPoller(0x3a9d690)._control(32)
[pid 249226] 11:36:05.370902 D mitogen.io: EpollPoller(0x3a9d6d0)._control(35)
[pid 249226] 11:36:05.370970 D mitogen.io: EpollPoller(0x3a96310).start_receive(56, None)
[pid 249226] 11:36:05.371417 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-4')._get_sleep(timeout=None, block=True, rfd=26, wfd=27)
[pid 249226] 11:36:05.371482 D mitogen.io: EpollPoller(0x3a99790).start_receive(59, None)
[pid 249226] 11:36:05.371582 D mitogen.io: EpollPoller(0x3a99850)._control(38)
[pid 249226] 11:36:05.371738 D mitogen.io: EpollPoller(0x3a96710)._control(41)
[pid 249226] 11:36:05.372000 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-3')._get_sleep(timeout=None, block=True, rfd=23, wfd=24)
[pid 249226] 11:36:05.372244 D mitogen.io: EpollPoller(0x3a99c10)._control(44)
[pid 249226] 11:36:05.372536 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-5')._get_sleep(timeout=None, block=True, rfd=29, wfd=30)
[pid 249226] 11:36:05.372590 D mitogen.io: EpollPoller(0x3a99810)._control(47)
[pid 249226] 11:36:05.372756 D mitogen.io: EpollPoller(0x3a99f90)._control(50)
[pid 249226] 11:36:05.372916 D mitogen.io: EpollPoller(0x3a99f50)._control(53)
[pid 249226] 11:36:05.373112 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-6')._get_sleep(timeout=None, block=True, rfd=32, wfd=33)
[pid 249226] 11:36:05.373322 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-7')._get_sleep(timeout=None, block=True, rfd=35, wfd=36)
[pid 249226] 11:36:05.373476 D mitogen.io: EpollPoller(0x3a96310)._control(56)
[pid 249226] 11:36:05.373783 D mitogen.io: EpollPoller(0x3a99790)._control(59)
[pid 249226] 11:36:05.373981 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-9')._get_sleep(timeout=None, block=True, rfd=38, wfd=39)
[pid 249226] 11:36:05.374123 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-8')._get_sleep(timeout=None, block=True, rfd=41, wfd=42)
[pid 249226] 11:36:05.374436 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-10')._get_sleep(timeout=None, block=True, rfd=44, wfd=45)
[pid 249226] 11:36:05.374630 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-11')._get_sleep(timeout=None, block=True, rfd=47, wfd=48)
[pid 249226] 11:36:05.374692 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-12')._get_sleep(timeout=None, block=True, rfd=50, wfd=51)
[pid 249226] 11:36:05.374963 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-13')._get_sleep(timeout=None, block=True, rfd=53, wfd=54)
[pid 249226] 11:36:05.375413 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-14')._get_sleep(timeout=None, block=True, rfd=56, wfd=57)
[pid 249226] 11:36:05.375682 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-15')._get_sleep(timeout=None, block=True, rfd=59, wfd=60)
[pid 249246] 11:36:05.395195 D mitogen: unix.connect(path='/tmp/mitogen_unix_Z1Qso1')
[pid 249226] 11:36:05.395721 D mitogen.io: EpollPoller(0x3a91bd0): POLLIN: 13
[pid 249226] 11:36:05.396220 D mitogen.io: Broker(0x3a91990).start_receive(mitogen.core.Stream(u'unix_client.249246'))
[pid 249226] 11:36:05.396459 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).defer() [immediate]
[pid 249226] 11:36:05.396696 D mitogen.io: EpollPoller(0x3a91bd0).start_receive(63, (<Side of mitogen.core.Stream(u'unix_client.249246') fd 63>, <bound method Stream.on_receive of mitogen.core.Stream(u'unix_client.249246')>))
[pid 249226] 11:36:05.396796 D mitogen.io: EpollPoller(0x3a91bd0)._control(63)
[pid 249226] 11:36:05.396977 D mitogen.io: Broker(0x3a91990)._loop_once(None, EpollPoller(0x3a91bd0))
[pid 249246] 11:36:05.396981 D mitogen: unix.connect(): local ID is 1, remote is 0
[pid 249246] 11:36:05.397300 D mitogen.io: Router(Broker(0x3a9b2d0)).add_handler(<bound method IdAllocator.on_allocate_id of IdAllocator(Router(Broker(0x3a9b2d0)))>, 105, True)
[pid 249246] 11:36:05.397449 D mitogen.io: Router(Broker(0x3a9b2d0)).add_handler(<bound method ModuleResponder._on_get_module of ModuleResponder(Router(Broker(0x3a9b2d0)))>, 100, True)
[pid 249246] 11:36:05.397575 D mitogen.io: Router(Broker(0x3a9b2d0)).add_handler(<bound method LogForwarder._on_forward_log of LogForwarder(Router(Broker(0x3a9b2d0)))>, 102, True)
[pid 249246] 11:36:05.397712 D mitogen.io: Router(Broker(0x3a9b2d0)).add_handler(<bound method RouteMonitor._on_add_route of <mitogen.parent.RouteMonitor object at 0x3a9b690>>, 103, True)
[pid 249246] 11:36:05.397813 D mitogen.io: Router(Broker(0x3a9b2d0)).add_handler(<bound method RouteMonitor._on_del_route of <mitogen.parent.RouteMonitor object at 0x3a9b690>>, 104, True)
[pid 249246] 11:36:05.397941 D mitogen.io: Router(Broker(0x3a9b2d0)).add_handler(<bound method Router._on_detaching of Router(Broker(0x3a9b2d0))>, 109, True)
[pid 249246] 11:36:05.398139 D mitogen.io: Broker(0x3a9b2d0).start_receive(mitogen.core.Stream(u'unix_listener.249226'))
[pid 249246] 11:36:05.398288 D mitogen.io: Waker(Broker(0x3a9b2d0) rfd=13, wfd=14).defer() [fd=14]
[pid 249246] 11:36:05.399273 D mitogen.io: Router(Broker(0x3a9b2d0)).add_handler(<bound method Receiver._on_receive of Receiver(Router(Broker(0x3a9b2d0)), None)>, 1000, False)
[pid 249246] 11:36:05.399441 D mitogen.io: EpollPoller(0x3a9bfd0): POLLIN: 13
[pid 249246] 11:36:05.399516 D mitogen.io: Waker(Broker(0x3a9b2d0) rfd=13, wfd=14).defer() [fd=14]
[pid 249246] 11:36:05.399658 D mitogen.io: Waker(Broker(0x3a9b2d0) rfd=13, wfd=14).on_receive()
[pid 249246] 11:36:05.399917 D mitogen.io: Receiver(Router(Broker(0x3a9b2d0)), 1000).get(timeout=None, block=True)
[pid 249246] 11:36:05.400082 D mitogen.io: EpollPoller(0x3a9bfd0).start_receive(17, (<Side of mitogen.core.Stream(u'unix_listener.249226') fd 17>, <bound method Stream.on_receive of mitogen.core.Stream(u'unix_listener.249226')>))
[pid 249246] 11:36:05.400171 D mitogen.io: Latch(0x3a9b110, size=0, t='MainThread').get(timeout=None, block=True)
[pid 249246] 11:36:05.400315 D mitogen.io: EpollPoller(0x3a9bfd0)._control(17)
[pid 249246] 11:36:05.400630 D mitogen.io: EpollPoller(0x3aa33d0).start_receive(16, None)
[pid 249246] 11:36:05.400787 D mitogen.io: Router(Broker(0x3a9b2d0))._async_route(Message(0, 1, 1, 110, 1000, "\x80\x02X'\x00\x00\x00ansible_mitogen.services.ContextServiceq\x01X\x03"..534), None)
[pid 249246] 11:36:05.400843 D mitogen.io: EpollPoller(0x3aa33d0)._control(16)
[pid 249246] 11:36:05.401066 D mitogen.io: mitogen.core.Stream(u'unix_listener.249226')._send(Message(0, 1, 1, 110, 1000, "\x80\x02X'\x00\x00\x00ansible_mitogen.services.ContextServiceq\x01X\x03"..534))
[pid 249246] 11:36:05.401358 D mitogen.io: Latch(0x3a9b110, size=0, t='MainThread')._get_sleep(timeout=None, block=True, rfd=16, wfd=19)
[pid 249246] 11:36:05.401410 D mitogen.io: Broker(0x3a9b2d0)._start_transmit(mitogen.core.Stream(u'unix_listener.249226'))
[pid 249246] 11:36:05.401620 D mitogen.io: EpollPoller(0x3a9bfd0).start_transmit(18, (<Side of mitogen.core.Stream(u'unix_listener.249226') fd 18>, <bound method Stream.on_transmit of mitogen.core.Stream(u'unix_listener.249226')>))
[pid 249246] 11:36:05.401722 D mitogen.io: EpollPoller(0x3a9bfd0)._control(18)
[pid 249246] 11:36:05.401822 D mitogen.io: Broker(0x3a9b2d0)._loop_once(None, EpollPoller(0x3a9bfd0))
[pid 249246] 11:36:05.401952 D mitogen.io: EpollPoller(0x3a9bfd0): POLLOUT: 18
[pid 249246] 11:36:05.402049 D mitogen.io: mitogen.core.Stream(u'unix_listener.249226').on_transmit()
[pid 249246] 11:36:05.402203 D mitogen.io: mitogen.core.Stream(u'unix_listener.249226').on_transmit() -> len 558
[pid 249246] 11:36:05.402303 D mitogen.io: Broker(0x3a9b2d0)._stop_transmit(mitogen.core.Stream(u'unix_listener.249226'))
[pid 249226] 11:36:05.402241 D mitogen.io: EpollPoller(0x3a91bd0): POLLIN: 63
[pid 249246] 11:36:05.402400 D mitogen.io: EpollPoller(0x3a9bfd0).stop_transmit(18)
[pid 249226] 11:36:05.402426 D mitogen.io: mitogen.core.Stream(u'unix_client.249246').on_receive()
[pid 249246] 11:36:05.402484 D mitogen.io: EpollPoller(0x3a9bfd0)._control(18)
[pid 249246] 11:36:05.402573 D mitogen.io: Broker(0x3a9b2d0)._loop_once(None, EpollPoller(0x3a9bfd0))
[pid 249226] 11:36:05.402619 D mitogen.io: Router(Broker(0x3a91990))._async_route(Message(0, 1, 1, 110, 1000, "\x80\x02X'\x00\x00\x00ansible_mitogen.services.ContextServiceq\x01X\x03"..534), mitogen.core.Stream(u'unix_client.249246'))
[pid 249226] 11:36:05.402770 D mitogen.io: Receiver(Router(Broker(0x3a91990)), 110)._on_receive(Message(0, 1, 0, 110, 1000, "\x80\x02X'\x00\x00\x00ansible_mitogen.services.ContextServiceq\x01X\x03"..534))
[pid 249226] 11:36:05.402914 D mitogen.io: Latch(0x3a961d0, size=0, t='mitogen-broker').put(Message(0, 1, 0, 110, 1000, "\x80\x02X'\x00\x00\x00ansible_mitogen.services.ContextServiceq\x01X\x03"..534))
[pid 249226] 11:36:05.403029 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen-broker').put(Receiver(Router(Broker(0x3a91990)), 110))
[pid 249226] 11:36:05.403140 D mitogen.io: Latch(0x3a96210, size=1, t='mitogen-broker').put() -> waking wfd=15
[pid 249226] 11:36:05.403281 D mitogen.io: Broker(0x3a91990)._loop_once(None, EpollPoller(0x3a91bd0))
[pid 249226] 11:36:05.403331 D mitogen.io: EpollPoller(0x3a962d0): POLLIN: 14
[pid 249226] 11:36:05.403644 D mitogen.io: Latch(0x3a96210, size=1, t='mitogen.service.Pool.3a96110.worker-0').get() wake -> Receiver(Router(Broker(0x3a91990)), 110)
[pid 249226] 11:36:05.403840 D mitogen.io: Receiver(Router(Broker(0x3a91990)), 110).get(timeout=None, block=False)
[pid 249226] 11:36:05.403989 D mitogen.io: Latch(0x3a961d0, size=1, t='mitogen.service.Pool.3a96110.worker-0').get(timeout=None, block=False)
[pid 249226] 11:36:05.404094 D mitogen.io: Latch(0x3a961d0, size=1, t='mitogen.service.Pool.3a96110.worker-0').get() -> Message(0, 1, 0, 110, 1000, "\x80\x02X'\x00\x00\x00ansible_mitogen.services.ContextServiceq\x01X\x03"..534)
[pid 249226] 11:36:05.404233 D mitogen.io: Message(0, 1, 0, 110, 1000, "\x80\x02X'\x00\x00\x00ansible_mitogen.services.ContextServiceq\x01X\x03"..534).unpickle()
[pid 249226] 11:36:05.404433 D mitogen.io: Message(0, 1, 0, 110, 1000, "\x80\x02X'\x00\x00\x00ansible_mitogen.services.ContextServiceq\x01X\x03"..534).unpickle()
[pid 249226] 11:36:05.405783 D mitogen: mitogen.ssh.Stream(u'default').connect()
[pid 249226] 11:36:05.537459 D mitogen: hybrid_tty_create_child() pid=249250 stdio=62, tty=16, cmd: "ssh" "-l" "tpusr" "-o" "IdentitiesOnly yes" "-i" "/home/tpusr/.ssh/id_rsa" "-o" "Compression yes" "-o" "ServerAliveInterval 15" "-o" "ServerAliveCountMax 3" "-o" "StrictHostKeyChecking yes" "-C" "-o" "ControlMaster=auto" "-o" "ControlPersist=60s" "host01" "/usr/bin/python" "-c" "'import codecs,os,sys;_=codecs.decode;exec(_(_(\"eNqFkVFLwzAUhZ/XX9G3m7Cwpt0QLASUPYgPIhSxD25Iu6Yu2CUhzVbnr/euE9bOB9/uxz0353CSsVyYdmaVlYQGjnUDUnWIUBv3SWgaTHCu9jYhnMWc0wtnbEgOt/GZN41pJcmG4IaQD6FDQMP2iPZN4dF1FwoRQlW4TmkIC131S/klN3tflI3s19G+dVGpdGSPfms0YM7JlWwq+sODdK0y+i2dr3tbqQ/KIcN99vDKYS3GZ2cNYkPGCzbGKZCd8uZD6tTb2mCcu51vG1ebbWF5nCaL2yS5oUADfK9zyksSM3h6fHnmnK80YI6NqbBuGizFOzkVXhkrNdYMrgQ6c7KoSJzMFwvK4FtZfKm24qLLGXQlnP6gtr8Gy34+93ql7v5T/00Zj1L+ADstsHw=\".encode(),\"base64\"),\"zip\"))'"
[pid 249226] 11:36:05.538518 D mitogen: mitogen.ssh.Stream(u'local.249250').connect(): child process stdin/stdout=62
[pid 249226] 11:36:05.538699 D mitogen.io: EpollPoller(0x3a9d990).start_receive(62, None)
[pid 249226] 11:36:05.538829 D mitogen.io: EpollPoller(0x3a9d990)._control(62)
[pid 249226] 11:36:05.538955 D mitogen.io: EpollPoller(0x3a9d990).start_receive(16, None)
[pid 249226] 11:36:05.539059 D mitogen.io: EpollPoller(0x3a9d990)._control(16)
[pid 249226] 11:36:05.612529 D mitogen.io: EpollPoller(0x3a9d990): POLLIN: 16
[pid 249226] 11:36:05.612709 D mitogen.io: iter_read(16) -> 'This system is for the use of authorized users only. Individuals using this\ncomputer system without authority or in excess of their authority are subject\nto having all of their activities on this system monitored and recorded by\nsystem personnel.                                                      \n\nIn the course of monitoring this system with regard to any unauthorized or\nimproper use or in the course of system maintenance the system personnel may\nhave insights into regular business activity. \n\nAnyone using this system expressly consents to such monitoring and is advised\nthat if such monitoring reveals possible evidence of improper activity, system\npersonnel may provide the evidence of such monitoring to internal Compliance\nand Security Officers who will - in the case of criminal offences - relay such\nincidents to law enforcement officials.\n\n**************************************************************\nNOTE: This system is connected to DOMAIN.COM,\nplease use your password.\n**************************************************************\n'
[pid 249226] 11:36:05.612935 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'This system is for the use of authorized users only. Individuals using this\n'
[pid 249226] 11:36:05.613052 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'computer system without authority or in excess of their authority are subject\n'
[pid 249226] 11:36:05.613185 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'to having all of their activities on this system monitored and recorded by\n'
[pid 249226] 11:36:05.613277 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'system personnel.                                                      \n'
[pid 249226] 11:36:05.613368 D mitogen: mitogen.ssh.Stream(u'local.249250'): received '\n'
[pid 249226] 11:36:05.613456 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'In the course of monitoring this system with regard to any unauthorized or\n'
[pid 249226] 11:36:05.613544 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'improper use or in the course of system maintenance the system personnel may\n'
[pid 249226] 11:36:05.613632 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'have insights into regular business activity. \n'
[pid 249226] 11:36:05.613719 D mitogen: mitogen.ssh.Stream(u'local.249250'): received '\n'
[pid 249226] 11:36:05.613804 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'Anyone using this system expressly consents to such monitoring and is advised\n'
[pid 249226] 11:36:05.613915 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'that if such monitoring reveals possible evidence of improper activity, system\n'
[pid 249226] 11:36:05.614019 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'personnel may provide the evidence of such monitoring to internal Compliance\n'
[pid 249226] 11:36:05.614112 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'and Security Officers who will - in the case of criminal offences - relay such\n'
[pid 249226] 11:36:05.614221 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'incidents to law enforcement officials.\n'
[pid 249226] 11:36:05.614316 D mitogen: mitogen.ssh.Stream(u'local.249250'): received '\n'
[pid 249226] 11:36:05.614399 D mitogen: mitogen.ssh.Stream(u'local.249250'): received '**************************************************************\n'
[pid 249226] 11:36:05.614485 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'NOTE: This system is connected to DOMAIN.COM,\n'
[pid 249226] 11:36:05.614579 D mitogen: mitogen.ssh.Stream(u'local.249250'): received 'please use your password.\n'
[pid 249226] 11:36:05.614706 D mitogen: mitogen.ssh.Stream(u'local.249250'): child process still alive, sending SIGTERM
[pid 249226] 11:36:05.614875 D mitogen.io: Latch(0x3a99bd0, size=0, t='mitogen.service.Pool.3a96110.worker-0').put((<class 'mitogen.ssh.PasswordError'>, PasswordError(u'SSH password was requested, but none specified',), <traceback object at 0x7f2c3802e9e0>))
[pid 249226] 11:36:05.615000 D mitogen.io: Latch(0x3a99bd0, size=1, t='mitogen.service.Pool.3a96110.worker-0').get(timeout=None, block=True)
[pid 249226] 11:36:05.615107 D mitogen.io: Latch(0x3a99bd0, size=1, t='mitogen.service.Pool.3a96110.worker-0').get() -> (<class 'mitogen.ssh.PasswordError'>, PasswordError(u'SSH password was requested, but none specified',), <traceback object at 0x7f2c3802e9e0>)
[pid 249226] 11:36:05.615350 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).defer() [fd=11]
[pid 249226] 11:36:05.615527 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-0').get(timeout=None, block=True)
[pid 249226] 11:36:05.615633 D mitogen.io: EpollPoller(0x3a91bd0): POLLIN: 9
[pid 249226] 11:36:05.615902 D mitogen.io: EpollPoller(0x3a991d0).start_receive(14, None)
[pid 249226] 11:36:05.616151 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).on_receive()
[pid 249226] 11:36:05.616403 D mitogen.io: EpollPoller(0x3a991d0)._control(14)
[pid 249226] 11:36:05.616570 D mitogen.io: Router(Broker(0x3a91990))._async_route(Message(1, 0, 0, 1000, None, '\x80\x02}q\x01(X\x0b\x00\x00\x00method_nameq\x02X\x03\x00\x00\x00sshq\x03X\x03\x00\x00\x00msgq\x04U.SSH '..134), None)
[pid 249226] 11:36:05.616839 D mitogen.io: Latch(0x3a96210, size=0, t='mitogen.service.Pool.3a96110.worker-0')._get_sleep(timeout=None, block=True, rfd=14, wfd=15)
[pid 249226] 11:36:05.616932 D mitogen.io: mitogen.core.Stream(u'unix_client.249246')._send(Message(1, 0, 0, 1000, None, '\x80\x02}q\x01(X\x0b\x00\x00\x00method_nameq\x02X\x03\x00\x00\x00sshq\x03X\x03\x00\x00\x00msgq\x04U.SSH '..134))
[pid 249226] 11:36:05.617268 D mitogen.io: Broker(0x3a91990)._start_transmit(mitogen.core.Stream(u'unix_client.249246'))
[pid 249226] 11:36:05.617370 D mitogen.io: EpollPoller(0x3a91bd0).start_transmit(64, (<Side of mitogen.core.Stream(u'unix_client.249246') fd 64>, <bound method Stream.on_transmit of mitogen.core.Stream(u'unix_client.249246')>))
[pid 249226] 11:36:05.617491 D mitogen.io: EpollPoller(0x3a91bd0)._control(64)
[pid 249226] 11:36:05.617615 D mitogen.io: Broker(0x3a91990)._loop_once(None, EpollPoller(0x3a91bd0))
[pid 249226] 11:36:05.617732 D mitogen.io: EpollPoller(0x3a91bd0): POLLOUT: 64
[pid 249226] 11:36:05.617873 D mitogen.io: mitogen.core.Stream(u'unix_client.249246').on_transmit()
[pid 249226] 11:36:05.618018 D mitogen.io: mitogen.core.Stream(u'unix_client.249246').on_transmit() -> len 158
[pid 249226] 11:36:05.618113 D mitogen.io: Broker(0x3a91990)._stop_transmit(mitogen.core.Stream(u'unix_client.249246'))
[pid 249246] 11:36:05.618053 D mitogen.io: EpollPoller(0x3a9bfd0): POLLIN: 17
[pid 249226] 11:36:05.618199 D mitogen.io: EpollPoller(0x3a91bd0).stop_transmit(64)
[pid 249246] 11:36:05.618230 D mitogen.io: mitogen.core.Stream(u'unix_listener.249226').on_receive()
[pid 249226] 11:36:05.618292 D mitogen.io: EpollPoller(0x3a91bd0)._control(64)
[pid 249246] 11:36:05.618368 D mitogen.io: Router(Broker(0x3a9b2d0))._async_route(Message(1, 0, 0, 1000, 0, '\x80\x02}q\x01(X\x0b\x00\x00\x00method_nameq\x02X\x03\x00\x00\x00sshq\x03X\x03\x00\x00\x00msgq\x04U.SSH '..134), mitogen.core.Stream(u'unix_listener.249226'))
[pid 249226] 11:36:05.618406 D mitogen.io: Broker(0x3a91990)._loop_once(None, EpollPoller(0x3a91bd0))
[pid 249246] 11:36:05.618500 D mitogen.io: Receiver(Router(Broker(0x3a9b2d0)), 1000)._on_receive(Message(1, 0, 0, 1000, 0, '\x80\x02}q\x01(X\x0b\x00\x00\x00method_nameq\x02X\x03\x00\x00\x00sshq\x03X\x03\x00\x00\x00msgq\x04U.SSH '..134))
[pid 249246] 11:36:05.618611 D mitogen.io: Latch(0x3a9b110, size=0, t='mitogen-broker').put(Message(1, 0, 0, 1000, 0, '\x80\x02}q\x01(X\x0b\x00\x00\x00method_nameq\x02X\x03\x00\x00\x00sshq\x03X\x03\x00\x00\x00msgq\x04U.SSH '..134))
[pid 249246] 11:36:05.618714 D mitogen.io: Latch(0x3a9b110, size=1, t='mitogen-broker').put() -> waking wfd=19
[pid 249246] 11:36:05.618835 D mitogen.io: Broker(0x3a9b2d0)._loop_once(None, EpollPoller(0x3a9bfd0))
[pid 249246] 11:36:05.618972 D mitogen.io: EpollPoller(0x3aa33d0): POLLIN: 16
[pid 249246] 11:36:05.619211 D mitogen.io: Latch(0x3a9b110, size=1, t='MainThread').get() wake -> Message(1, 0, 0, 1000, 0, '\x80\x02}q\x01(X\x0b\x00\x00\x00method_nameq\x02X\x03\x00\x00\x00sshq\x03X\x03\x00\x00\x00msgq\x04U.SSH '..134)
[pid 249246] 11:36:05.619364 D mitogen.io: Message(1, 0, 0, 1000, 0, '\x80\x02}q\x01(X\x0b\x00\x00\x00method_nameq\x02X\x03\x00\x00\x00sshq\x03X\x03\x00\x00\x00msgq\x04U.SSH '..134).unpickle()
[pid 249246] 11:36:05.619649 D mitogen.io: Waker(Broker(0x3a9b2d0) rfd=13, wfd=14).defer() [fd=14]
[pid 249246] 11:36:05.619822 D mitogen.io: EpollPoller(0x3a9bfd0): POLLIN: 13
[pid 249246] 11:36:05.619984 D mitogen.io: Waker(Broker(0x3a9b2d0) rfd=13, wfd=14).on_receive()
[pid 249246] 11:36:05.620103 D mitogen.io: Waker(Broker(0x3a9b2d0) rfd=13, wfd=14).defer() [immediate]
[pid 249246] 11:36:05.620238 D mitogen: mitogen.core.Stream(u'unix_listener.249226').on_disconnect()
[pid 249246] 11:36:05.620359 D mitogen.io: Broker(0x3a9b2d0).stop_receive(mitogen.core.Stream(u'unix_listener.249226'))
[pid 249246] 11:36:05.620459 D mitogen.io: Waker(Broker(0x3a9b2d0) rfd=13, wfd=14).defer() [immediate]
[pid 249246] 11:36:05.620542 D mitogen.io: EpollPoller(0x3a9bfd0).stop_receive(17)
[pid 249246] 11:36:05.620625 D mitogen.io: EpollPoller(0x3a9bfd0)._control(17)
[pid 249246] 11:36:05.620711 D mitogen.io: <Side of mitogen.core.Stream(u'unix_listener.249226') fd 17>.close()
[pid 249246] 11:36:05.620797 D mitogen.io: Broker(0x3a9b2d0)._stop_transmit(mitogen.core.Stream(u'unix_listener.249226'))
[pid 249246] 11:36:05.620917 D mitogen.io: EpollPoller(0x3a9bfd0).stop_transmit(18)
[pid 249246] 11:36:05.621008 D mitogen.io: EpollPoller(0x3a9bfd0)._control(18)
[pid 249246] 11:36:05.621110 D mitogen.io: <Side of mitogen.core.Stream(u'unix_listener.249226') fd 18>.close()
[pid 249246] 11:36:05.621278 D mitogen: Waker(Broker(0x3a9b2d0) rfd=13, wfd=14).on_disconnect()
[pid 249226] 11:36:05.621291 D mitogen.io: EpollPoller(0x3a91bd0): POLLIN: 63
[pid 249246] 11:36:05.621383 D mitogen.io: Broker(0x3a9b2d0).stop_receive(Waker(Broker(0x3a9b2d0) rfd=13, wfd=14))
[pid 249226] 11:36:05.621412 D mitogen.io: mitogen.core.Stream(u'unix_client.249246').on_receive()
[pid 249246] 11:36:05.621462 D mitogen.io: Waker(Broker(0x3a9b2d0) rfd=13, wfd=14).defer() [immediate]
[pid 249246] 11:36:05.621534 D mitogen.io: EpollPoller(0x3a9bfd0).stop_receive(13)
[pid 249226] 11:36:05.621516 D mitogen: mitogen.core.Stream(u'unix_client.249246').on_disconnect()
[pid 249246] 11:36:05.621605 D mitogen.io: EpollPoller(0x3a9bfd0)._control(13)
[pid 249226] 11:36:05.621620 D mitogen.io: Broker(0x3a91990).stop_receive(mitogen.core.Stream(u'unix_client.249246'))
[pid 249246] 11:36:05.621678 D mitogen.io: <Side of Waker(Broker(0x3a9b2d0) rfd=13, wfd=14) fd 13>.close()
[pid 249226] 11:36:05.621705 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).defer() [immediate]
[pid 249246] 11:36:05.621755 D mitogen.io: Broker(0x3a9b2d0)._stop_transmit(Waker(Broker(0x3a9b2d0) rfd=13, wfd=14))
[pid 249226] 11:36:05.621784 D mitogen.io: EpollPoller(0x3a91bd0).stop_receive(63)
[pid 249246] 11:36:05.621828 D mitogen.io: EpollPoller(0x3a9bfd0).stop_transmit(14)
[pid 249226] 11:36:05.621876 D mitogen.io: EpollPoller(0x3a91bd0)._control(63)
[pid 249246] 11:36:05.621921 D mitogen.io: EpollPoller(0x3a9bfd0)._control(14)
[pid 249226] 11:36:05.621968 D mitogen.io: <Side of mitogen.core.Stream(u'unix_client.249246') fd 63>.close()
[pid 249246] 11:36:05.622017 D mitogen.io: <Side of Waker(Broker(0x3a9b2d0) rfd=13, wfd=14) fd 14>.close()
[pid 249226] 11:36:05.622056 D mitogen.io: Broker(0x3a91990)._stop_transmit(mitogen.core.Stream(u'unix_client.249246'))
[pid 249226] 11:36:05.622164 D mitogen.io: EpollPoller(0x3a91bd0).stop_transmit(64)
[pid 249226] 11:36:05.622245 D mitogen.io: EpollPoller(0x3a91bd0)._control(64)
[pid 249226] 11:36:05.622317 D mitogen.io: <Side of mitogen.core.Stream(u'unix_client.249246') fd 64>.close()
[pid 249226] 11:36:05.622440 D mitogen.io: Broker(0x3a91990)._loop_once(None, EpollPoller(0x3a91bd0))
host01 | UNREACHABLE! => {
    "changed": false,
    "msg": "SSH password was requested, but none specified",
    "unreachable": true
}
tpusr@localhost:~> [pid 249226] 11:36:05.682640 D mitogen.io: io_op(<built-in method recv of _socket.socket object at 0x3a8f240>) -> OSError: [Errno 104] Connection reset by peer
[pid 249226] 11:36:05.683511 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).defer() [fd=11]
[pid 249226] 11:36:05.683822 D mitogen.io: EpollPoller(0x3a91bd0): POLLIN: 9
[pid 249226] 11:36:05.684087 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).on_receive()
[pid 249226] 11:36:05.684369 D mitogen.io: EpollPoller(0x3a96ad0): POLLIN: 17
[pid 249226] 11:36:05.684548 D mitogen.io: EpollPoller(0x3a89f90): POLLIN: 26
[pid 249226] 11:36:05.684651 D mitogen.io: EpollPoller(0x3a96e10): POLLIN: 23
[pid 249226] 11:36:05.684960 D mitogen.io: EpollPoller(0x3a99c90): POLLIN: 29
[pid 249226] 11:36:05.685037 D mitogen.io: EpollPoller(0x3a99150): POLLIN: 20
[pid 249226] 11:36:05.685322 D mitogen.io: EpollPoller(0x3a9d690): POLLIN: 32
[pid 249226] 11:36:05.686904 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-1'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.685388 D mitogen.io: EpollPoller(0x3a9d6d0): POLLIN: 35
[pid 249226] 11:36:05.687262 D mitogen: Waker(Broker(0x3a91990) rfd=9, wfd=11).on_disconnect()
[pid 249226] 11:36:05.685669 D mitogen.io: EpollPoller(0x3a99850): POLLIN: 38
[pid 249226] 11:36:05.687332 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-4'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.687451 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-3'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.685756 D mitogen.io: EpollPoller(0x3a99c10): POLLIN: 44
[pid 249226] 11:36:05.687747 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-2'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.687838 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-5'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.685820 D mitogen.io: EpollPoller(0x3a96710): POLLIN: 41
[pid 249226] 11:36:05.685965 D mitogen.io: EpollPoller(0x3a99f90): POLLIN: 50
[pid 249226] 11:36:05.686158 D mitogen.io: EpollPoller(0x3a99810): POLLIN: 47
[pid 249226] 11:36:05.686354 D mitogen.io: EpollPoller(0x3a99f50): POLLIN: 53
[pid 249226] 11:36:05.688535 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-6'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.686530 D mitogen.io: EpollPoller(0x3a99790): POLLIN: 59
[pid 249226] 11:36:05.688788 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-7'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.686634 D mitogen.io: EpollPoller(0x3a991d0): POLLIN: 14
[pid 249226] 11:36:05.687085 D mitogen.io: EpollPoller(0x3a96310): POLLIN: 56
[pid 249226] 11:36:05.689452 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-9'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.688356 D mitogen.io: Broker(0x3a91990).stop_receive(Waker(Broker(0x3a91990) rfd=9, wfd=11))
[pid 249226] 11:36:05.689644 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-10'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.690140 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-12'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.692402 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).defer() [immediate]
[pid 249226] 11:36:05.690423 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-8'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.692763 D mitogen.io: EpollPoller(0x3a91bd0).stop_receive(9)
[pid 249226] 11:36:05.690497 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-11'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.693177 D mitogen.io: EpollPoller(0x3a91bd0)._control(9)
[pid 249226] 11:36:05.691241 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-13'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.693559 D mitogen.io: <Side of Waker(Broker(0x3a91990) rfd=9, wfd=11) fd 9>.close()
[pid 249226] 11:36:05.691440 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-15'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.691726 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-0'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.694045 D mitogen.io: Broker(0x3a91990)._stop_transmit(Waker(Broker(0x3a91990) rfd=9, wfd=11))
[pid 249226] 11:36:05.692190 I mitogen: mitogen.service.Pool(0x3a96110, size=16, th='mitogen.service.Pool.3a96110.worker-14'): channel or latch closed, exitting: None
[pid 249226] 11:36:05.694426 D mitogen.io: EpollPoller(0x3a91bd0).stop_transmit(11)
[pid 249226] 11:36:05.694663 D mitogen.io: EpollPoller(0x3a91bd0)._control(11)
[pid 249226] 11:36:05.694759 D mitogen.io: <Side of Waker(Broker(0x3a91990) rfd=9, wfd=11) fd 11>.close()
[pid 249226] 11:36:05.694895 D mitogen: <mitogen.unix.Listener object at 0x3a91d50>.on_disconnect()
[pid 249226] 11:36:05.694997 D mitogen.io: Broker(0x3a91990).stop_receive(<mitogen.unix.Listener object at 0x3a91d50>)
[pid 249226] 11:36:05.695097 D mitogen.io: Waker(Broker(0x3a91990) rfd=9, wfd=11).defer() [immediate]
[pid 249226] 11:36:05.695203 D mitogen.io: EpollPoller(0x3a91bd0).stop_receive(13)
[pid 249226] 11:36:05.695291 D mitogen.io: EpollPoller(0x3a91bd0)._control(13)
[pid 249226] 11:36:05.695406 D mitogen.io: <Side of <mitogen.unix.Listener object at 0x3a91d50> fd 13>.close()
[pid 249226] 11:36:05.695587 D mitogen.io: Receiver(Router(Broker(0x3a91990)), 110)._on_receive(Message(None, 0, 0, None, 999, ''..0))
[pid 249226] 11:36:05.695699 D mitogen.io: Latch(0x3a961d0, size=0, t='mitogen-broker').put(Message(None, 0, 0, None, 999, ''..0))
@dw

This comment has been minimized.

Owner

dw commented Jul 17, 2018

This is due to the presence of the word 'password' in the login banner. We can suppress the login banner by passing 'ssh -q' (e.g. via ssh_args in ansible.cfg), but then we lose diagnostic output.

I will investigate updating the logic to only assume a password prompt if no newline appears following the prompt, which seems like a robust test, however it is sensitive to timing and buffering weirdness (SSH process may sleep indefinitely after writing 'password' but before writing the newline), so this might break things worse than they already are.

Please try with the -q workaround above added to your ansible.cfg, and I will investigate some logic fix.

Really the correct solution here is to move to Paramiko, but that's quite a lot of work.

@dw

This comment has been minimized.

Owner

dw commented Jul 17, 2018

Yep.. the ideal solution is probably a combination of '-o "LogLevel ERROR"' by default, /and/ a slightly racy newline check. That way the racy aspect is only likely to be triggered when running with mitogen_ssh_debug_level=3

dw added a commit that referenced this issue Jul 17, 2018

issue #307: suppress SSH login banner when verbosity is disabled.
Login banner may include the password prompt, and there is no race-free
way to detect the difference between the banner and the prompt.

dw added a commit that referenced this issue Jul 17, 2018

issue #307: require partial line when matching interactive prompt.
This is a best-effort attempt to avoid SSHd banner spam from breaking
our password entry loop.

dw added a commit that referenced this issue Jul 17, 2018

issue #307: require partial line when matching interactive prompt.
This is a best-effort attempt to avoid SSHd banner spam from breaking
our password entry loop.

Closes #307.

@dw dw closed this in 830a133 Jul 17, 2018

@dw

This comment has been minimized.

Owner

dw commented Jul 17, 2018

Hi there,

The fix for this is now on master -- it will make it into the next release. Meanwhile feel free to run from master, or use the previously mentioned workaround until a release is cut.

@falbanese

This comment has been minimized.

falbanese commented Jul 18, 2018

Hi,
thank you for the quick fix. I confirm that adding '-q' to the ssh args bypasses the problem.
I think I will keep evaluating the current stable version and update to the next one as soon as it is ready.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment