ssm connection plugin fails at gathering facts

[MVJosh]

SUMMARY

Using the ssm plugin, playbooks fail at the gathering facts stage, with:

An exception occurred during task execution. To see the full traceback, use -vvv. The error was: ValueError: invalid literal for int() with base 10: "echo $'\\n'$?"
fatal: [i-xxxxx]: FAILED! => {"msg": "Unexpected failure during module execution.", "stdout": ""}

If using gather_facts: false, the same error occurs at the first task

As far as I can tell, SSM is configured correctly: I can run aws ssm start-session --target i-xxxxx from my ansible host and successfully get a shell on the target host.

ISSUE TYPE

• Bug Report

COMPONENT NAME

ssm connection plugin

ANSIBLE VERSION

ansible 2.9.9
  config file = /etc/ansible/ansible.cfg
  configured module search path = ['/home/ubuntu/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/ubuntu/.local/lib/python3.8/site-packages/ansible
  executable location = /home/ubuntu/.local/bin/ansible
  python version = 3.8.2 (default, Apr 27 2020, 15:53:34) [GCC 9.3.0]

CONFIGURATION

INVENTORY_ENABLED(/etc/ansible/ansible.cfg) = ['aws_ec2']

OS / ENVIRONMENT

Both the instance running Ansible and the target (SSM-managed) instance are regular ubuntu 20.04 AMIs

STEPS TO REPRODUCE

• Launch 2 EC2 instances running Ubuntu 20.04 (in same AWS region)
• Install ansible, boto3, aws cli & sms plugin on first instance
• Run AWS Systems Manager quick start (using default roles & choosing all instances as targets)
• confirm that SSM can start a shell from Ansible to second instance: aws ssm start-session --target i-xxxxx
• Enable ansible aws_ec2 inventory plugin
• Run the following playbook with the attached inventory config:

# Playbook

- hosts: all
  vars:
    ansible_connection: community.aws.aws_ssm
    ansible_aws_ssm_region: eu-west-2 # substitute for your region
  tasks:
    - name: test
      command:
        cmd: ls -l

# aws_ec2.yaml inventory

plugin: aws_ec2
regions:
  - eu-west-2
keyed_groups:
  - prefix: tag
    key: tags
  - prefix: aws_region
    key: placement.region
hostnames:
  - instance-id
compose:
  ansible_host: instance-id

Run:

ansible-playbook -i aws_ec2.yaml -c community.aws.aws_ssm test-playbook.yaml

EXPECTED RESULTS

Playbook runs successfully with no errors

ACTUAL RESULTS

Playbook errors on gathering facts stage, with:

An exception occurred during task execution. To see the full traceback, use -vvv. The error was: ValueError: invalid literal for int() with base 10: "echo $'\\n'$?"
fatal: [i-xxxxx]: FAILED! => {"msg": "Unexpected failure during module execution.", "stdout": ""}

with -vvvv verbosity:

ansible-playbook 2.9.9
  config file = /etc/ansible/ansible.cfg
  configured module search path = ['/home/ubuntu/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/ubuntu/.local/lib/python3.8/site-packages/ansible
  executable location = /home/ubuntu/.local/bin/ansible-playbook
  python version = 3.8.2 (default, Apr 27 2020, 15:53:34) [GCC 9.3.0]
Using /etc/ansible/ansible.cfg as config file
setting up inventory plugins
Parsed /home/ubuntu/aws_ec2.yaml inventory source with aws_ec2 plugin
Loading callback plugin default of type stdout, v2.0 from /home/ubuntu/.local/lib/python3.8/site-packages/ansible/plugins/callback/default.py

PLAYBOOK: test_ssm.yaml ****************************************************************************************************************************************************************************************
Positional arguments: test_ssm.yaml
verbosity: 4
connection: community.aws.aws_ssm
timeout: 10
become_method: sudo
tags: ('all',)
inventory: ('/home/ubuntu/aws_ec2.yaml',)
forks: 5
1 plays in test_ssm.yaml

PLAY [all] *****************************************************************************************************************************************************************************************************

TASK [Gathering Facts] *****************************************************************************************************************************************************************************************
task path: /home/ubuntu/test_ssm.yaml:1
<i-xxxxx> ESTABLISH SSM CONNECTION TO: i-xxxxx
<i-xxxxx> SSM COMMAND: ['/usr/local/bin/session-manager-plugin', '{"SessionId": "i-xxxxx-yyyyy", "TokenValue": "XXXXX", "StreamUrl": "wss://ssmmessages.eu-west-2.amazonaws.com/v1/data-channel/i-yyyyy-zzzzz?role=publish_subscribe", "ResponseMetadata": {"RequestId": "xxxx-xxxx-xxxx-xxxx", "HTTPStatusCode": 200, "HTTPHeaders": {"x-amzn-requestid": "xxxx-xxxx-xxxx-xxxx-xxxx", "content-type": "application/x-amz-json-1.1", "content-length": "626", "date": "Fri, 19 Jun 2020 14:41:52 GMT"}, "RetryAttempts": 0}}', 'eu-west-2', 'StartSession', '', '{"Target": "i-xxxxx"}', 'https://ssm.eu-west-2.amazonaws.com']
<i-xxxxx> SSM CONNECTION ID: i-xxxx-xxxxx
<i-xxxxx> EXEC echo ~
<i-xxxxx> _wrap_command: 'echo XXXXX
echo ~
echo $'\n'$?
echo YYYYY
'
<i-xxxxx> EXEC stdout line: 
<i-xxxxx> EXEC stdout line: Starting session with SessionId: i-xxxxx-yyyyy
<i-xxxxx> EXEC remaining: 60
<i-xxxxx> EXEC stdout line: $ stty -echo
<i-xxxxx> EXEC stdout line: PS1=''
<i-xxxxx> EXEC stdout line: echo XXXXX
<i-xxxxx> EXEC stdout line: echo ~
<i-xxxxx> EXEC stdout line: echo $'\n'$?
<i-xxxxx> EXEC stdout line: echo YYYYY
<i-xxxxx> POST_PROCESS: echo ~
echo $'\n'$?
<i-xxxxx> ssm_retry: attempt: 0, caught exception(invalid literal for int() with base 10: "echo $'\\n'$?") from cmd (echo ~...), pausing for 0 seconds
<i-xxxxx> CLOSING SSM CONNECTION TO: i-xxxxx
<i-xxxxx> TERMINATE SSM SESSION: i-xxxxx-yyyyy
<i-xxxxx> ESTABLISH SSM CONNECTION TO: i-xxxxx
<i-xxxxx> SSM COMMAND: ['/usr/local/bin/session-manager-plugin', '{"SessionId": "i-xxxxx-yyyyy", "TokenValue": "XXXXX", "StreamUrl": "wss://ssmmessages.eu-west-2.amazonaws.com/v1/data-channel/i-yyyyy-zzzzz?role=publish_subscribe", "ResponseMetadata": {"RequestId": "xxxx-xxxx-xxxx-xxxx-xxxx", "HTTPStatusCode": 200, "HTTPHeaders": {"x-amzn-requestid": "xxxx-xxxx-xxxx-xxxx-xxxx", "content-type": "application/x-amz-json-1.1", "content-length": "626", "date": "Fri, 19 Jun 2020 14:41:53 GMT"}, "RetryAttempts": 0}}', 'eu-west-2', 'StartSession', '', '{"Target": "i-xxxxx"}', 'https://ssm.eu-west-2.amazonaws.com']
<i-xxxxx> SSM CONNECTION ID: i-xxxx-xxxx
<i-xxxxx> EXEC echo ~
<i-xxxxx> _wrap_command: 'echo YYYYY
echo ~
echo $'\n'$?
echo ZZZZZ
'
<i-xxxxx> EXEC stdout line: 
<i-xxxxx> EXEC stdout line: Starting session with SessionId: i-xxxx-yyyy
<i-xxxxx> EXEC remaining: 60
<i-xxxxx> EXEC stdout line: $ stty -echo
<i-xxxxx> EXEC stdout line: PS1=''
<i-xxxxx> EXEC stdout line: echo YYYYY
<i-xxxxx> EXEC stdout line: echo ~
<i-xxxxx> EXEC stdout line: echo $'\n'$?
<i-xxxxx> EXEC stdout line: echo ZZZZZ
<i-xxxxx> POST_PROCESS: echo ~
echo $'\n'$?
<i-xxxxx> CLOSING SSM CONNECTION TO: i-xxxxx
<i-xxxxx> TERMINATE SSM SESSION: i-xxxxx-yyyyy
The full traceback is:
Traceback (most recent call last):
  File "/home/ubuntu/.local/lib/python3.8/site-packages/ansible/executor/task_executor.py", line 146, in run
    res = self._execute()
  File "/home/ubuntu/.local/lib/python3.8/site-packages/ansible/executor/task_executor.py", line 645, in _execute
    result = self._handler.run(task_vars=variables)
  File "/home/ubuntu/.local/lib/python3.8/site-packages/ansible/plugins/action/gather_facts.py", line 79, in run
    res = self._execute_module(module_name=fact_module, module_args=mod_args, task_vars=task_vars, wrap_async=False)
  File "/home/ubuntu/.local/lib/python3.8/site-packages/ansible/plugins/action/__init__.py", line 780, in _execute_module
    self._make_tmp_path()
  File "/home/ubuntu/.local/lib/python3.8/site-packages/ansible/plugins/action/__init__.py", line 343, in _make_tmp_path
    tmpdir = self._remote_expand_user(self.get_shell_option('remote_tmp', default='~/.ansible/tmp'), sudoable=False)
  File "/home/ubuntu/.local/lib/python3.8/site-packages/ansible/plugins/action/__init__.py", line 664, in _remote_expand_user
    data = self._low_level_execute_command(cmd, sudoable=False)
  File "/home/ubuntu/.local/lib/python3.8/site-packages/ansible/plugins/action/__init__.py", line 1075, in _low_level_execute_command
    rc, stdout, stderr = self._connection.exec_command(cmd, in_data=in_data, sudoable=sudoable)
  File "/home/ubuntu/.ansible/collections/ansible_collections/community/aws/plugins/connection/aws_ssm.py", line 197, in wrapped
    return_tuple = func(self, *args, **kwargs)
  File "/home/ubuntu/.ansible/collections/ansible_collections/community/aws/plugins/connection/aws_ssm.py", line 389, in exec_command
    returncode, stdout = self._post_process(stdout, mark_begin)
  File "/home/ubuntu/.ansible/collections/ansible_collections/community/aws/plugins/connection/aws_ssm.py", line 442, in _post_process
    returncode = int(stdout.splitlines()[-2])
ValueError: invalid literal for int() with base 10: "echo $'\\n'$?"
fatal: [i-xxxxx]: FAILED! => {
    "msg": "Unexpected failure during module execution.",
    "stdout": ""
}

[ilyavaiser]

Same issue, unusual plugin

[abeluck]

I looked into this, and there are several things wrong I think.

See this line

            cmd = "echo " + mark_start + "\n" + cmd + "\necho $'\\n'$?\n" + "echo " + mark_end + "\n"

The shell used by the session-manager is sh, which does not support bashisms like $'\n' to print a new line.
See the difference:

sh

$ echo $'\n'$?
$
0

bash

$ echo $'\n'$?

0

---

However, that might be a red herring. Notice the output:

<i-xxxxx> EXEC stdout line: $ stty -echo
<i-xxxxx> EXEC stdout line: PS1=''
<i-xxxxx> EXEC stdout line: echo YYYYY
<i-xxxxx> EXEC stdout line: echo ~
<i-xxxxx> EXEC stdout line: echo $'\n'$?
<i-xxxxx> EXEC stdout line: echo ZZZZZ

That is the input commands, not the stdout. Where is the output?

[abeluck]

Here is a workaround that avoids sh entirely by starting a bash shell.

--- a/plugins/connection/aws_ssm.py	2020-09-03 18:43:43.818000000 +0200
+++ b/plugins/connection/aws_ssm.py	2020-09-03 18:43:19.805000000 +0200
@@ -288,11 +288,17 @@
 
         profile_name = ''
         region_name = self.get_option('region')
-        ssm_parameters = dict()
 
         client = boto3.client('ssm', region_name=region_name)
         self._client = client
-        response = client.start_session(Target=self.instance_id, Parameters=ssm_parameters)
+
+        if self.is_windows:
+            ssm_parameters = dict()
+            response = client.start_session(Target=self.instance_id, Parameters=ssm_parameters)
+        else:
+            ssm_parameters = {"command": ["bash -l"]}
+            response = client.start_session(Target=self.instance_id, DocumentName="AWS-StartInteractiveCommand", Parameters=ssm_parameters)
+
         self._session_id = response['SessionId']
 
         cmd = [

[DanielFallon]

I looked at this for a bit today and found that you were right to be skeptical @abeluck .

The issue appears to actually be in _prepare_terminal. The current code does not wait for tty -echo to return before sending additional bytes. This causes all characters that are sent prior to the return of tty -echo to be printed and any characters written afterwards to not be printed.

Since the commands are sent so quickly, the terminal prints all lines. Then we break out of the loop because <start_mark> is definitely present in echo <start_mark>. You can quickly fix the behavior by adding a delay (and also probably the fix for the bashism) Here are some logs to demonstrate:

After removing the loop breakout:

Loading callback plugin minimal of type stdout, v2.0 from /usr/lib/python3.8/site-packages/ansible/plugins/callback/minimal.py
META: ran handlers
<ip-___-__-_-___.ec2.internal> ESTABLISH SSM CONNECTION TO: i-0cc44a1e2f7995c53
<ip-___-__-_-___.ec2.internal> SSM COMMAND: ['/usr/local/bin/session-manager-plugin',...]
<ip-___-__-_-___.ec2.internal> SSM CONNECTION ID: DanFallon-095d5d09e63ce624c
<ip-___-__-_-___.ec2.internal> EXEC echo ~ubuntu
<ip-___-__-_-___.ec2.internal> _wrap_command: 'echo PKjewgTIHJcLjaXeCjlasDjfZw
echo ~ubuntu
echo $'\n'$?
echo uZmXXhFRmkCzCEZEPjWMQlNiIF
'
<ip-___-__-_-___.ec2.internal> EXEC stdout line: 
<ip-___-__-_-___.ec2.internal> EXEC stdout line: Starting session with SessionId: DanFallon-095d5d09e63ce624c
<ip-___-__-_-___.ec2.internal> EXEC remaining: 60
<ip-___-__-_-___.ec2.internal> EXEC stdout line: $ stty -echo ; 
<ip-___-__-_-___.ec2.internal> EXEC stdout line: PS1='' ; 
<ip-___-__-_-___.ec2.internal> EXEC stdout line: echo PKjewgTIHJcLjaXeCjlasDjfZw
<ip-___-__-_-___.ec2.internal> EXEC stdout line: echo ~ubuntu
<ip-___-__-_-___.ec2.internal> EXEC stdout line: echo $'\n'$?
<ip-___-__-_-___.ec2.internal> EXEC stdout line: echo uZmXXhFRmkCzCEZEPjWMQlNiIF
<ip-___-__-_-___.ec2.internal> EXEC stdout line: $ PKjewgTIHJcLjaXeCjlasDjfZw
<ip-___-__-_-___.ec2.internal> EXEC stdout line: /home/ubuntu
<ip-___-__-_-___.ec2.internal> EXEC stdout line: $
<ip-___-__-_-___.ec2.internal> EXEC stdout line: 0
<ip-___-__-_-___.ec2.internal> EXEC stdout line: uZmXXhFRmkCzCEZEPjWMQlNiIF
<ip-___-__-_-___.ec2.internal> EXEC remaining: 59
<ip-___-__-_-___.ec2.internal> EXEC remaining: 58
<ip-___-__-_-___.ec2.internal> EXEC remaining: 57
<ip-___-__-_-___.ec2.internal> EXEC remaining: 56
<ip-___-__-_-___.ec2.internal> EXEC remaining: 55
<ip-___-__-_-___.ec2.internal> EXEC remaining: 54
<ip-___-__-_-___.ec2.internal> EXEC remaining: 53
...

After adding a 5 second delay

Loading callback plugin minimal of type stdout, v2.0 from /usr/lib/python3.8/site-packages/ansible/plugins/callback/minimal.py
META: ran handlers
<ip-___-__-_-___.ec2.internal> ESTABLISH SSM CONNECTION TO: i-0cc44a1e2f7995c53
<ip-___-__-_-___.ec2.internal> SSM COMMAND: ['/usr/local/bin/session-manager-plugin', ...]
Sleeping for 5 seconds.
<ip-___-__-_-___.ec2.internal> SSM CONNECTION ID: DanFallon-05193c016e933c229
<ip-___-__-_-___.ec2.internal> EXEC echo ~ubuntu
<ip-___-__-_-___.ec2.internal> _wrap_command: 'echo KylNOeAyCbfmTzlCZGrbHiYnSm
echo ~ubuntu
echo $'\n'$?
echo PujmuNjsUIsmGZzoUwNAUvowBk
'
<ip-___-__-_-___.ec2.internal> EXEC stdout line: 
<ip-___-__-_-___.ec2.internal> EXEC stdout line: Starting session with SessionId: DanFallon-05193c016e933c229
<ip-___-__-_-___.ec2.internal> EXEC stdout line: $ stty -echo ; 
<ip-___-__-_-___.ec2.internal> EXEC stdout line: PS1='' ; 
<ip-___-__-_-___.ec2.internal> EXEC stdout line: $ KylNOeAyCbfmTzlCZGrbHiYnSm
<ip-___-__-_-___.ec2.internal> EXEC stdout line: /home/ubuntu
<ip-___-__-_-___.ec2.internal> EXEC stdout line: $
<ip-___-__-_-___.ec2.internal> EXEC stdout line: 0
<ip-___-__-_-___.ec2.internal> EXEC stdout line: PujmuNjsUIsmGZzoUwNAUvowBk
<ip-___-__-_-___.ec2.internal> EXEC remaining: 60
<ip-___-__-_-___.ec2.internal> EXEC remaining: 59
<ip-___-__-_-___.ec2.internal> EXEC remaining: 58
<ip-___-__-_-___.ec2.internal> EXEC remaining: 57
<ip-___-__-_-___.ec2.internal> EXEC remaining: 56
<ip-___-__-_-___.ec2.internal> EXEC remaining: 55

[abeluck]

Would love to see these fixes land, and maybe get some tests around this plugin (not sure how that would work).

We bailed on the ssm plugin for now and are running ansible over ssh over ssm, which means we still have to manage ssh keys on instances (though we don't need a bastion any longer).

[mikeneiderhauser]

Another strange issue that i see related to this during gathering facts is the AnsiballZ_setup.py that is run does something to mess with the shell and always hits EXEC remaining and always times out after without echoing to stdout the new line and the end mark. My remote host is running an older version of python so I'm initially thinking thats related. Trying to stand up a venv on remote to use as env

[DanielFallon]

Here's a patch that I'm willing to contribute (haven't gotten a chance to set up a fork yet)

• Replaces echo with printf because it's more portable and robust
• waits on receiving command replies before starting additional executions.

Problems I still see:

• Does aws_ssm.py need to support python2? I don't think my code is compatible. (and I thought boto3 was python3 only, maybe I'm wrong)
• cmd (line 517) when executed could eat the end_mark command. maybe we could disconnect cmd's stdin? Any solution I thought of for this makes some assumptions about the command or the terminal that I didn't like.

Anywho, I freely release the below under a GPL V3.0+ license like the files from which the were derived. I can look at figuring out the contributor agreement/etc later this week.

diff --git a/plugins/connection/aws_ssm.py b/plugins/connection/aws_ssm.py
index 7f7d692..4dc3965 100644
--- a/plugins/connection/aws_ssm.py
+++ b/plugins/connection/aws_ssm.py
@@ -412,11 +412,97 @@ class Connection(ConnectionBase):
     def _prepare_terminal(self):
         ''' perform any one-time terminal settings '''
 
-        if not self.is_windows:
-            cmd = "stty -echo\n" + "PS1=''\n"
-            cmd = to_bytes(cmd, errors='surrogate_or_strict')
-            self._session.stdin.write(cmd)
+        # No windows setup for now
+        if self.is_windows:
+            return
+
+        # *_complete variables are 3 valued:
+        #   - None: not started
+        #   - False: started
+        #   - True: complete
+
 
+        startup_complete = False
+        startup_reply = re.compile(
+            r"Starting session with SessionId:\W+" +
+            re.escape(self._session_id) +
+            r"\r\n\$ ", re.MULTILINE)
+
+        disable_echo_complete = None
+        disable_echo_cmd = to_bytes("stty -echo\n", errors='surrogate_or_strict')
+        disable_echo_reply = re.compile(
+            r"stty \-echo" +
+            r"\r\r\n\$", re.MULTILINE
+        )
+
+        disable_prompt_complete = None
+        end_mark = "".join([random.choice(string.ascii_letters) for i in xrange(self.MARK_LENGTH)])
+        disable_prompt_cmd = to_bytes(
+            "PS1='' ; printf '\\n%s\\n' '" + end_mark + "'\n",
+            errors='surrogate_or_strict')
+        disable_prompt_reply = re.compile(
+            r"\r\r\n" +
+            re.escape(end_mark) +
+            r"\r\r\n", re.MULTILINE
+        )
+
+        stdout = ""
+        cursor = 0
+        # Custom command execution for when we're waiting for startup
+        stop_time = int(round(time.time())) + self.get_option('ssm_timeout')
+        while (not disable_prompt_complete) and (self._session.poll() is None):
+            remaining = stop_time - int(round(time.time()))
+            if remaining < 1:
+                self._timeout = True
+                display.vvvv(u"PRE timeout stdout: {0}".format(to_bytes(stdout)), host=self.host)
+                raise AnsibleConnectionFailure("SSM start_session timeout on host: %s"
+                                               % self.instance_id)
+            if self._poll_stdout.poll(1000):
+                stdout += to_text(self._stdout.read(1024))
+                display.vvvv(u"PRE stdout line: {0}".format(to_bytes(stdout)), host=self.host)
+            else:
+                display.vvvv(u"PRE remaining: {0}".format(remaining), host=self.host)
+
+            # wait til prompt is ready
+            if startup_complete is False:
+                match = startup_reply.search(stdout,cursor)
+                if match:
+                    display.vvvv(u"PRE startup output received", host=self.host)
+                    cursor = match.end()
+                    startup_complete = True
+                    
+
+            # disable echo
+            if startup_complete and (disable_echo_complete is None):
+                display.vvvv(u"PRE Disabling Echo: {0}".format(disable_echo_cmd), host=self.host)
+                self._session.stdin.write(disable_echo_cmd)
+                disable_echo_complete = False
+
+            if disable_echo_complete is False:
+                match = disable_echo_reply.search(stdout)
+                if match:
+                    stdout = stdout[match.end():]
+                    disable_echo_complete = True
+            
+
+            # disable prompt
+            if disable_echo_complete and disable_prompt_complete is None:
+                display.vvvv(u"PRE Disabling Prompt: {0}".format(disable_prompt_cmd), host=self.host)
+                self._session.stdin.write(disable_prompt_cmd)
+                disable_prompt_complete = False
+
+            if disable_prompt_complete is False:
+                match = disable_prompt_reply.search(stdout)
+                if match:
+                    stdout = stdout[match.end():]
+                    disable_prompt_complete = True
+        
+        if not disable_prompt_complete:
+            raise AnsibleConnectionFailure("SSM process closed during _prepare_terminal on host: %s"
+                                               % self.instance_id)
+        else:
+            display.vvv(u"PRE Terminal configured", host=self.host)
+            
     def _wrap_command(self, cmd, sudoable, mark_start, mark_end):
         ''' wrap command so stdout and status can be extracted '''
 
@@ -427,7 +513,9 @@ class Connection(ConnectionBase):
         else:
             if sudoable:
                 cmd = "sudo " + cmd
-            cmd = "echo " + mark_start + "\n" + cmd + "\necho $'\\n'$?\n" + "echo " + mark_end + "\n"
+            cmd = ("printf '%s\\n' '{0}' ;\n".format(mark_start) +
+                cmd + 
+                " ;\nprintf '\\n%s\\n%s\\n' \"$?\" '{0}' ;\n".format(mark_end))
 
         display.vvvv(u"_wrap_command: '{0}'".format(to_text(cmd)), host=self.host)
         return cmd

[mikeneiderhauser]

Im willing to try it because im stuck. My executing node is running py3. My endpoint is only running 2.7 (legacy os). So the plugin being py3 only should be fine. The py2 issues may just be with what ansible packages up and sends over to the endpoint

[mikeneiderhauser]

@DanielFallon thanks for the patch. Had to change your ssm_timeout to timeout for the self.get_option call.

upon executing im getting stuck in a PRE remaining loop eg prompt not ready during gathering facts

[DanielFallon]

The change in get_option call is because my patch was for the development version instead of the currently released version (they just changed it from timeout to ssm_timeout)

can you post a redacted log with debug level at least 4? (-vvvv)
I'd like to see which part of the setup loop it's getting stuck in.

There are sort of 3 phases:
first, waits for it to receive the string:

Starting session with SessionId:

second, waits to receive the string:

stty -echo
$

and the third wait's to receive a custom generated end string:

<end_mark>

I expected this code to be a bit fragile but fail safe. Maybe I should add some more detail to the timeout exception

[mikeneiderhauser]

I can grab you a log, but may take some time, my inventory script now isn't populating as expected which sets up the s3 bucket name, and instance id.

[DanielFallon]

it's also worth noting that I only tested this with a sort of hello world example. I wouldn't be surprised if there are still things that don't work. I do think that some sort of scripted regression testing would be very valuable for this as it is fragile and could be broken by:

• changes to ansible
• changes to the ssm session plugin
• changes to the aws api
• probably differences in a hosts' /etc/profile

all things to enumerate and test

[mikeneiderhauser]

Does your patch apply to the 1.2 tagged release or on the main branch?

[mikeneiderhauser]

Please see sanitized output. I took stock 1.2 and added just your patch and got the following

$ ansible-playbook $ANS_VAULT_FLAGS --limit TEST-GRP --user testuser --tags debug-vars common_aws_node.yml -vvvvvv
ansible-playbook 2.9.9
  config file = /home/user/ansibletest/ansible.cfg
  configured module search path = ['/home/user/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
  ansible python module location = /home/user/venvs/ansible/lib64/python3.6/site-packages/ansible
  executable location = /home/user/venvs/ansible/bin/ansible-playbook
  python version = 3.6.8 (default, Apr  2 2020, 13:34:55) [GCC 4.8.5 20150623 (Red Hat 4.8.5-39)]
Using /home/user/ansibletest/ansible.cfg as config file
Reading vault password file: XXXX
Reading vault password file: XXXX
Reading vault password file: XXXX
setting up inventory plugins
host_list declined parsing /home/user/ansibletest/inventories/dynamic_inv.yml as it did not pass its verify_file() method
Start parsing DYN inventory
Blacklisted hosts
Done parsing DYN inventory
Parsed /home/user/ansibletest/inventories/dynamic_inv.yml inventory source with auto plugin
statically imported: /home/user/ansibletest/roles/basic-provisioning/tasks/10_install_start_aws_ssm.yml
Loading callback plugin default of type stdout, v2.0 from /home/user/venvs/ansible/lib64/python3.6/site-packages/ansible/plugins/callback/default.py

PLAYBOOK: common_aws_node.yml ************************************************************************************************************************************************************************************************************************
Positional arguments: common_aws_node.yml
verbosity: 6
remote_user: testuser
connection: smart
timeout: 10
become_method: sudo
tags: ('debug-vars',)
inventory: ('/home/user/ansibletest/inventories/dynamic_inv.yml',)
subset: TEST-GRP
vault_ids: XXXX
forks: 5
7 plays in common_aws_node.yml

PLAY [provision] *************************************************************************************************************************************************************************************************************************************
META: ran handlers
META: ran handlers
META: ran handlers

--- CUT --- (Skipped roles)

PLAY [debug-vars] ************************************************************************************************************************************************************************************************************************************

TASK [Gathering Facts] *******************************************************************************************************************************************************************************************************************************
task path: /home/user/ansibletest/common_aws_node.yml:59
<10.x.x.x> ESTABLISH SSM CONNECTION TO: i-0AWS_INSTANCEID
<10.x.x.x> SSM COMMAND: ['/usr/local/bin/session-manager-plugin', '{"SessionId": "[email protected]", "TokenValue": "XXXCUTXXX", "StreamUrl": "wss://ssmmessages.us-east-1.amazonaws.com/v1/data-channel/[email protected]?role=publish_subscribe", "ResponseMetadata": {"RequestId": "XXX REQ ID XXX", "HTTPStatusCode": 200, "HTTPHeaders": {"server": "Server", "date": "Fri, 02 Oct 2020 14:49:59 GMT", "content-type": "application/x-amz-json-1.1", "content-length": "668", "connection": "keep-alive", "x-amzn-requestid": "XXX amzn id XXX"}, "RetryAttempts": 0}}', 'us-east-1', 'StartSession', '', '{"Target": "i-0AWS_INSTANCEID"}', 'https://ssm.us-east-1.amazonaws.com']
<10.x.x.x> PRE stdout line: b'\r\nStarting session with SessionId: [email protected]\r\n'
<10.x.x.x> PRE remaining: 60
<10.x.x.x> PRE stdout line: b'\r\nStarting session with SessionId: [email protected]\r\n\x1b[?1034hsh-4.2$ '
<10.x.x.x> PRE remaining: 59
<10.x.x.x> PRE remaining: 58
--- CUT ---
<10.x.x.x> PRE remaining: 3
<10.x.x.x> PRE remaining: 2
<10.x.x.x> PRE remaining: 1
<10.x.x.x> PRE timeout stdout: b'\r\nStarting session with SessionId: [email protected]\r\n\x1b[?1034hsh-4.2$ '
<10.x.x.x> ssm_retry: attempt: 0, cmd (echo ~testuser...), pausing for 0 seconds
<10.x.x.x> CLOSING SSM CONNECTION TO: i-0AWS_INSTANCEID
<10.x.x.x> TERMINATE SSM SESSION: [email protected]
<10.x.x.x> ESTABLISH SSM CONNECTION TO: i-0AWS_INSTANCEID
<10.x.x.x> SSM COMMAND: ['/usr/local/bin/session-manager-plugin', '{"SessionId": "[email protected]", "TokenValue": "XXXCUTXXX", "StreamUrl": "wss://ssmmessages.us-east-1.amazonaws.com/v1/data-channel/[email protected]?role=publish_subscribe", "ResponseMetadata": {"RequestId": "XXX REQ ID XXX", "HTTPStatusCode": 200, "HTTPHeaders": {"server": "Server", "date": "Fri, 02 Oct 2020 14:51:00 GMT", "content-type": "application/x-amz-json-1.1", "content-length": "668", "connection": "keep-alive", "x-amzn-requestid": "XXX amzn id XXX"}, "RetryAttempts": 0}}', 'us-east-1', 'StartSession', '', '{"Target": "i-0AWS_INSTANCEID"}', 'https://ssm.us-east-1.amazonaws.com']
<10.x.x.x> PRE stdout line: b'\r\nStarting session with SessionId: [email protected]\r\n'
<10.x.x.x> PRE remaining: 60
<10.x.x.x> PRE stdout line: b'\r\nStarting session with SessionId: [email protected]\r\n\x1b[?1034hsh-4.2$ '
<10.x.x.x> PRE remaining: 59
<10.x.x.x> PRE remaining: 58

I also added the bash shell patch as well (but changed bash -l to bash --noprofile -l) with a similar result

[mikeneiderhauser]

I modified some of the re's that are in the patch (mainly removing the \r\n's). Now I'm hitting the same issue. The AnsiballZ_setup.py gets transferred and executed. It prints out the json for the facts, but i never get the end mark. As in I never see the second printf output

sudo sudo -H -S -n  -u root /bin/sh -c 'echo BECOME-SUCCESS-lzrbkhycxnugzysliwrhdukemyhhtyde ; /usr/bin/python /home/maintuser/.ansible/tmp/ansible-tmp-1601664494.6311371-10330-41749016017816/AnsiballZ_setup.py' ;
printf '\n%s\n%s\n' "$?" 'icjRpqBJJHvCxBxLeqZMYeJKhQ' ;

Then back to the retry loop

[DanielFallon]

the bash patch is definitely incompatible with mine. (because the regex would definitely have to change.)

does python ansible-tmp-1601664494.6311371-10330-41749016017816/AnsiballZ_setup.py open stdin? if yes, then it might be eating the printf command (meaning that the shell would never receive it.)

This is one of the things I was worried about in my comment above. I kind of want to look at some other connection plugins and see how they handle this, because I think a lot of pieces of this are pretty fragile and I want to see others ideas.

maybe instead of clearing the prompt, we could set it to an end_mark so that the shell will print it.

[mikeneiderhauser]

I tried both sh and bash (with and w/o modding the re's) and both have similar behavior. I do think that AnsiballZ_setup.py is doing something to stdin.

[DanielFallon]

This is not an SSM specific solution, but I'm tempted to try out using SendSSHPublicKey from the EC2 instance connect api and then wrapping the ssh connection library instead. Feels like it might be generally more stable (and would support sftp as well)

SSM might still be necessary for the tunnel, but I'm not sure piping commands to stdin is ever really going to be partiuclarly stable.

Any reason why ssmStartSession is superior that I should know about?

[DanielFallon]

Looking at this a bit closer, it looks like the right way to address this if use of SSM is wanted is to add a parameter like ssm_exec_document_name. I had not gotten a chance to use SSM much prior to now and wasn't super familiar with its api. The document name in the current version of the api can define most of the behavior of how an interactive session starts, although it unfortunately seems to still start with a raw shell (see here: https://github.com/aws/amazon-ssm-agent/blob/b9654b268afcb7e70a9cc6c6d9b7d2a676f5b468/agent/session/plugins/shell/shell_unix.go#L53 )

Because customization of the shell is so fragile, it's probably worthwhile to provide a sane default and then allow users to override the --document-name provided to the session to configure things further. To facilitate this, the important part is to establish a protocol for communicating stdout and the exit code back to the client (preferably one that is slightly more robust than what is present now so that a user can always produce working results for their system)

I'll give it another half an hour today and post results

[mikeneiderhauser]

@DanielFallon would be interested to see your results. Seems to be a step in the right direction.

[jiba21]

Here is a workaround that avoids sh entirely by starting a bash shell.

--- a/plugins/connection/aws_ssm.py	2020-09-03 18:43:43.818000000 +0200
+++ b/plugins/connection/aws_ssm.py	2020-09-03 18:43:19.805000000 +0200
@@ -288,11 +288,17 @@
 
         profile_name = ''
         region_name = self.get_option('region')
-        ssm_parameters = dict()
 
         client = boto3.client('ssm', region_name=region_name)
         self._client = client
-        response = client.start_session(Target=self.instance_id, Parameters=ssm_parameters)
+
+        if self.is_windows:
+            ssm_parameters = dict()
+            response = client.start_session(Target=self.instance_id, Parameters=ssm_parameters)
+        else:
+            ssm_parameters = {"command": ["bash -l"]}
+            response = client.start_session(Target=self.instance_id, DocumentName="AWS-StartInteractiveCommand", Parameters=ssm_parameters)
+
         self._session_id = response['SessionId']
 
         cmd = [

I think this solution work partially, because is not closing the sessions in session manager. And the system open one session for every one task in Ansible. This causes if I execute a playbook with 10 tasks, 10 session is opening and no closing xd ...

[mikeneiderhauser]

The above wont work if there is anything custom about the systems (or users) bash profile that changes what is presented on stdout. I've tried this even with --noprofile and it still hangs for me when gathering facts.

[ChenTsungYu]

I have the same issue with Debian e.g. ubuntu

[eliskovets]

As a work-around you can switch default shell to bash instead of sh in Session Manager preferences:
https://aws.amazon.com/premiumsupport/knowledge-center/ssm-session-manager-change-shell/

[hexsel]

As with @eliskovets , I had to change the default shell to bash, but I used the instructions at https://unix.stackexchange.com/questions/442510/how-to-use-bash-for-sh-in-ubuntu.

[jagibson]

For me, changing the shell using the profile in the Session Manager setting broke logins to Amazon Linux 2 for some reason (which was working OK before). What worked was changing the link that /bin/sh uses via the "sudo dpkg-reconfigure dash" command in Ubuntu. Thanks @eliskovets!

[bedge]

Ran into the identical thing: https://stackoverflow.com/questions/68734815/ansible-aws-ssm-connectivity-plugin-ciphertext-refers-to-a-customer-master
Disabling KMS encryption in the SSM config fixed it:

Does this warrant a separate bug?
Or, am I missing a config value to enable the "KMS encryption" in the session manager preferences?

(Just confirmed while replicating that the default shell needed to NOT be dash as well)

[bedge]

(Update, moving away from dash has no immediate downside)

Re: Changing the ubuntu default shell fix - ansible version

# See "/var/cache/debconf/config.dat" for name of config item after changing manually
- name: aws-ssm ansible plugin fails if dash is the default shell
  ansible.builtin.debconf:
    name: dash/sh
    question: dash/sh
    value: false
    vtype: boolean

[jagibson]

@bedge your vtype should be boolean and I don't think you should be quoting 'false'.

I haven't tested with cloudinit yet but hopefully that's all you need to do.

[bedge]

@jagibson Confirmed your suggestion os correct for the ansible (no) dash fix:

# See "/var/cache/debconf/config.dat" for name of config item after changing manually
- name: aws-ssm ansible plugin fails if dash is the default shell
  ansible.builtin.debconf:
    name: dash/sh
    question: dash/sh
    value: false
    vtype: boolean

thanks

Now the remaining issue is the s3 permissions. Seems to work only with

{
    "Version": "2012-10-17",
    "Statement": [
        {
            "Sid": "",
            "Effect": "Allow",
            "Action": "s3:*",
            "Resource": "*"
        }
    ]
}

Any attempt to reign that in and it starts failing with:

2021-08-13 20:29:58 INFO [ssm-agent-worker] [MessageGatewayService] Sending reply {
  "SchemaVersion": 1,
  "TaskId": "[email protected]",
  "Topic": "agent_task_complete",
  "FinalTaskStatus": "Failed",
  "IsRoutingFailure": false,
  "AwsAccountId": "",
  "InstanceId": "i-01c257e02de698f9b",
  "Output": "Couldn't start the session because we are unable to validate encryption on Amazon S3 bucket. Error: AccessDenied: Access Denied\n\tstatus code: 403, request id: F20PG8SWSH8V4J6Z, host id: 9JY/CcOq6C6Bswaw7AJfbGLcTlzD8scLt/nEBncsI8ac9GPTEeVMDTU7B2yWcgDxn0W+fsZINW4=",
  "S3Bucket": "",
  "S3UrlSuffix": "",
  "CwlGroup": "",
  "CwlStream": ""
}

Is there any way to restrict the s3 access to a specific bucket:///... ?

[bedge]

After some unreliable success with dash removed as the default for /bin/sh on the targets, I switched to setting the shell profile in the AWS session-manager prefs and that seems to be more reliable.
ie: hasn't failed with that set, and consistently fails with it unset.
Not sure how this is different from removing the /bin/sh -> dash association, but the end result is definitely better.

[shinebayar-g]

Does this plugin work?

1st attempt:

An exception occurred during task execution. To see the full traceback, use -vvv. The error was: ValueError: invalid literal for int() with base 10: "echo $'\\n'$?"
ubuntu2004 | FAILED! => {
    "msg": "Unexpected failure during module execution.",
    "stdout": ""
}

2nd attempt:
Changed default shell to /bin/bash in Session Manager's Preferences as suggested above.

An exception occurred during task execution. To see the full traceback, use -vvv. The error was: TypeError: expected string or bytes-like object
ubuntu2004 | FAILED! => {
    "msg": "Unexpected failure during module execution.",
    "stdout": ""
}

[wilinger]

Why isn't anyone using the fix here #583 ? It seems to work flawlessly for me.

[Hokwang]

I found this problem occurs windows also.

[ulyr]

Recent AWS Linux AMIs add some unicode characters to inputs/outputs that can cause this same error message, if you recently launched a new instance / updated AMIs try the following fix - #1756 (comment)