accelerate mode hanging?

I’m having trouble using accelerate. It fails with the message “timed out while waiting to receive data”

Here’s the output from -vvvv if there’s no accelerate process running:

attempting connection to play.clara.io via the accelerated port 5099
failed, retrying…
failed, retrying…
failed, retrying…
Could not connect via the accelerated connection, exceeded # of tries
Falling back to ssh to startup accelerated mode
attempting to start up the accelerate daemon…
<play.clara.io> ESTABLISH CONNECTION FOR USER: blarsen
<play.clara.io> EXEC [‘ssh’, ‘-tt’, ‘-vvv’, ‘-o’, ‘ControlMaster=auto’, ‘-o’, ‘ControlPersist=60s’, ‘-o’, ‘ControlPath=/home/blarsen/.ansible/cp/ansible-ssh-%h-%p-%r’, ‘-o’, ‘StrictHostKeyChecking=no’, ‘-o’, ‘Port=22’, ‘-o’, ‘KbdInteractiveAuthentication=no’, ‘-o’, ‘PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey’, ‘-o’, ‘PasswordAuthentication=no’, ‘-o’, ‘ConnectTimeout=10’, ‘play.clara.io’, “/bin/sh -c ‘mkdir -p $HOME/.ansible/tmp/ansible-1383078590.97-85382680194668 && chmod a+rx $HOME/.ansible/tmp/ansible-1383078590.97-85382680194668 && echo $HOME/.ansible/tmp/ansible-1383078590.97-85382680194668’”]
<play.clara.io> PUT /tmp/tmp0zkOQy TO /home/blarsen/.ansible/tmp/ansible-1383078590.97-85382680194668/accelerate
<play.clara.io> EXEC [‘ssh’, ‘-tt’, ‘-vvv’, ‘-o’, ‘ControlMaster=auto’, ‘-o’, ‘ControlPersist=60s’, ‘-o’, ‘ControlPath=/home/blarsen/.ansible/cp/ansible-ssh-%h-%p-%r’, ‘-o’, ‘StrictHostKeyChecking=no’, ‘-o’, ‘Port=22’, ‘-o’, ‘KbdInteractiveAuthentication=no’, ‘-o’, ‘PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey’, ‘-o’, ‘PasswordAuthentication=no’, ‘-o’, ‘ConnectTimeout=10’, ‘play.clara.io’, “/bin/sh -c ‘/usr/bin/python /home/blarsen/.ansible/tmp/ansible-1383078590.97-85382680194668/accelerate; rm -rf /home/blarsen/.ansible/tmp/ansible-1383078590.97-85382680194668/ >/dev/null 2>&1’”]
attempting connection to play.clara.io via the accelerated port 5099
EXEC COMMAND mkdir -p $HOME/.ansible/tmp/ansible-1383078595.79-111934745781373 && chmod a+rx $HOME/.ansible/tmp/ansible-1383078595.79-111934745781373 && echo $HOME/.ansible/tmp/ansible-1383078595.79-111934745781373
play.clara.io: in recv_data(), waiting for the header
play.clara.io: got the header, unpacking
play.clara.io: data received so far (expecting 153): 0
play.clara.io: received all of the data, returning
play.clara.io: received the response
<play.clara.io> REMOTE_MODULE setup
<play.clara.io> PUT /tmp/tmpqzlsxw TO /home/blarsen/.ansible/tmp/ansible-1383078595.79-111934745781373/setup
PUT file is 126471 bytes
file position currently 0, file size is 126471
play.clara.io: in recv_data(), waiting for the header
play.clara.io: got the header, unpacking
play.clara.io: data received so far (expecting 57): 0
play.clara.io: received all of the data, returning
file position currently 20880, file size is 126471
play.clara.io: in recv_data(), waiting for the header
play.clara.io: got the header, unpacking
play.clara.io: data received so far (expecting 57): 0
play.clara.io: received all of the data, returning
file position currently 41760, file size is 126471
play.clara.io: in recv_data(), waiting for the header
play.clara.io: got the header, unpacking
play.clara.io: data received so far (expecting 57): 0
play.clara.io: received all of the data, returning
file position currently 62640, file size is 126471
play.clara.io: in recv_data(), waiting for the header
play.clara.io: got the header, unpacking
play.clara.io: data received so far (expecting 57): 0
play.clara.io: received all of the data, returning
file position currently 83520, file size is 126471
play.clara.io: in recv_data(), waiting for the header
play.clara.io: got the header, unpacking
play.clara.io: data received so far (expecting 57): 0
play.clara.io: received all of the data, returning
file position currently 104400, file size is 126471
play.clara.io: in recv_data(), waiting for the header
play.clara.io: got the header, unpacking
play.clara.io: data received so far (expecting 57): 0
play.clara.io: received all of the data, returning
file position currently 125280, file size is 126471
play.clara.io: in recv_data(), waiting for the header
play.clara.io: got the header, unpacking
play.clara.io: data received so far (expecting 57): 0
play.clara.io: received all of the data, returning
waiting for final response after PUT
play.clara.io: in recv_data(), waiting for the header
play.clara.io: got the header, unpacking
play.clara.io: data received so far (expecting 57): 0
play.clara.io: received all of the data, returning
EXEC COMMAND /bin/sh -c ‘sudo -k && sudo -H -S -p “[sudo via ansible, key=sqewehmfvpofpzcclsjmfpxhalofnakw] password: " -u root /bin/sh -c '”’“‘/usr/bin/python /home/blarsen/.ansible/tmp/ansible-1383078595.79-111934745781373/setup; rm -rf /home/blarsen/.ansible/tmp/ansible-1383078595.79-111934745781373/ >/dev/null 2>&1’”‘"’’
play.clara.io: in recv_data(), waiting for the header
fatal: [play.clara.io] => timed out while waiting to receive data

If I try it again I get:

GATHERING FACTS ***************************************************************
attempting connection to play.clara.io via the accelerated port 5099
EXEC COMMAND mkdir -p $HOME/.ansible/tmp/ansible-1383079073.01-237707214605160 && chmod a+rx $HOME/.ansible/tmp/ansible-1383079073.01-237707214605160 && echo $HOME/.ansible/tmp/ansible-1383079073.01-237707214605160
play.clara.io: in recv_data(), waiting for the header
fatal: [play.clara.io] => timed out while waiting to receive data

I get the similar results for both 1.3.3 and a fresh checkout from github.

Is there any other information you’d like me to provide?

thanks,
Bryan

last I looked, you cannot use sudo and accelerated mode.

According to the docs:

As noted above, accelerated mode also supports running tasks via sudo, however there are two important caveats:

  • You must remove requiretty from your sudoers options.
  • Prompting for the sudo password is not yet supported, so the NOPASSWD option is required for sudo’ed commands.

ah, sorry, they must have updated it since I looked last, then it didn’t support sudo in any case.

What is in the logs on the other side of the connection? With -vvvv you should see it logging quite a bit to /var/log/messages (or wherever your default syslog target goes). I saw something similar to this when my DNS entries in resolv.conf were hosed up, as it was taking forever to run the setup module.

I went to check my syslog, and it was totally empty. Restarted syslog and it started working…

thanks for the hint,
Bryan

Personally I think we should insist on removing requiretty from sudoers because the whole default pseudo-tty setup (which is there only for sudo) is causing more problems than it is worth.

     https://github.com/ansible/ansible/pull/1801

By default processes should not ask interactive questions (and block waiting for answers) when run through Ansible.

     ansible -vvvv somesystem -m shell -a 'read a'

The above should not wait until it times out...

I’m happy to make it a docs suggestion, offhand I’m not sure we cause any problems with it off, but we should still work ok with it on.