SSH Error when trying to provision

Hi,

I’m getting a new error when trying to provision the remote server. I mention that I can connect via ssh manually but using ansible I get this error then for a period of time can’t connect with ssh manually.

[WARNING]: Unhandled error in Python interpreter discovery for host
104.248.129.27: Failed to connect to the host via ssh: OpenSSH_8.1p1, LibreSSL
2.7.3  debug1: Reading configuration data /Users/marius/.ssh/config  debug1:
/Users/marius/.ssh/config line 5: Applying options for *  debug1: Reading
configuration data /etc/ssh/ssh_config  debug1: /etc/ssh/ssh_config line 47:
Applying options for *  debug2: resolve_canonicalize: hostname 104.248.129.27
is address  debug1: auto-mux: Trying existing master  debug1: Control socket
"/Users/marius/.ansible/cp/3b57dd76c8" does not exist  debug2:
ssh_connect_direct  debug1: Connecting to 104.248.129.27 [104.248.129.27] port
22.  debug2: fd 3 setting O_NONBLOCK  debug1: connect to address 104.248.129.27
port 22: Connection refused  ssh: connect to host 104.248.129.27 port 22:
Connection refused
Using module file /Users/marius/Projects/lightstock-next/trellis/.trellis/virtualenv/lib/python3.9/site-packages/ansible/modules/setup.py
Pipelining is enabled.
<104.248.129.27> ESTABLISH SSH CONNECTION FOR USER: lightstock
<104.248.129.27> SSH: EXEC ssh -vvv -o ForwardAgent=yes -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="lightstock"' -o ConnectTimeout=10 -o 'ControlPath="/Users/marius/.ansible/cp/3b57dd76c8"' 104.248.129.27 '/bin/sh -c '"'"'sudo -H -S -p "[sudo via ansible, key=ojcowqnmiphnknbqjsxscrkqafchrnnr] password:" -u root /bin/sh -c '"'"'"'"'"'"'"'"'echo BECOME-SUCCESS-ojcowqnmiphnknbqjsxscrkqafchrnnr ; /usr/bin/python'"'"'"'"'"'"'"'"' && sleep 0'"'"''
<104.248.129.27> ssh_retry: attempt: 1, ssh return code is 255. cmd ([b'ssh', b'-vvv', b'-o', b'ForwardAgent=yes', b'-o', b'ControlMaster=auto', b'-o', b'ControlPersist=60s', b'-o', b'KbdInteractiveAuthentication=no', b'-o', b'PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey', b'-o', b'PasswordAuthentication=no', b'-o', b'User="lightstock"', b'-o', b'ConnectTimeout=10', b'-o', b'ControlPath="/Users/marius/.ansible/cp/3b57dd76c8"', b'104.248.129.27', b'/bin/sh -c \'sudo -H -S -p "[sudo via ansible, key=ojcowqnmiphnknbqjsxscrkqafchrnnr] password:" -u root /bin/sh -c \'"\'"\'echo BECOME-SUCCESS-ojcowqnmiphnknbqjsxscrkqafchrnnr ; /usr/bin/python\'"\'"\' && sleep 0\'']...), pausing for 0 seconds
<104.248.129.27> SSH: EXEC ssh -vvv -o ForwardAgent=yes -o ControlMaster=auto -o ControlPersist=60s -o KbdInteractiveAuthentication=no -o PreferredAuthentications=gssapi-with-mic,gssapi-keyex,hostbased,publickey -o PasswordAuthentication=no -o 'User="lightstock"' -o ConnectTimeout=10 -o 'ControlPath="/Users/marius/.ansible/cp/3b57dd76c8"' 104.248.129.27 '/bin/sh -c '"'"'sudo -H -S -p "[sudo via ansible, key=ojcowqnmiphnknbqjsxscrkqafchrnnr] password:" -u root /bin/sh -c '"'"'"'"'"'"'"'"'echo BECOME-SUCCESS-ojcowqnmiphnknbqjsxscrkqafchrnnr ; /usr/bin/python'"'"'"'"'"'"'"'"' && sleep 0'"'"''
System info:
  Ansible 2.12.7; Darwin
  Trellis version (per changelog): "Add built-in fail2ban filters"
---------------------------------------------------
Data could not be sent to remote host "104.248.129.27". Make sure this host
can be reached over ssh: OpenSSH_8.1p1, LibreSSL 2.7.3
debug1: Reading configuration data /Users/marius/.ssh/config
debug1: /Users/marius/.ssh/config line 5: Applying options for *
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 47: Applying options for *
debug2: resolve_canonicalize: hostname 104.248.129.27 is address
debug1: auto-mux: Trying existing master
debug1: Control socket "/Users/marius/.ansible/cp/3b57dd76c8" does not exist
debug2: ssh_connect_direct
debug1: Connecting to 104.248.129.27 [104.248.129.27] port 22.
debug2: fd 3 setting O_NONBLOCK
debug1: connect to address 104.248.129.27 port 22: Connection refused
ssh: connect to host 104.248.129.27 port 22: Connection refused
fatal: [104.248.129.27]: UNREACHABLE! => {
    "changed": false,
    "unreachable": true
}

Deploy works as it should but if I try to provision the server before then I can’t deploy for a period of time then it works.

Data could not be sent to remote host "104.248.129.27". Make sure this host
can be reached over ssh: ssh: connect to host 104.248.129.27 port 22:
Connection refused
fatal: [104.248.129.27]: UNREACHABLE! => {"changed": false, "unreachable": true}

macOS Catalina Version: 10.15.7
Python 3.9.13

Hey,

Did you add your ssh key before provision?

ssh-add -K

@Jacek yes the key was added since I can ssh manually. I’ve run ssh-add -K again and getting the same error.

It’s strange since I can ssh into the server manually with web and admin users but when ansible tries I get that error and then for 5min or so can’t ssh manually. It looks like I’m getting banned.

I’ve accessed /var/log/fail2ban.log and I’m getting banned after I try to provision the server using trellis-cli.

#/var/log/fail2ban.log
....
2022-06-27 17:59:23,932 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-27 17:59:23
2022-06-27 17:59:23,933 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-27 17:59:23
2022-06-27 17:59:24,007 fail2ban.actions        [728]: NOTICE  [sshd] Ban 86.127.225.2
2022-06-27 17:59:24,227 fail2ban.actions        [728]: NOTICE  [ssh] Ban 86.127.225.2
2022-06-27 18:09:23,093 fail2ban.actions        [728]: NOTICE  [ssh] Unban 86.127.225.2
2022-06-27 18:09:24,871 fail2ban.actions        [728]: NOTICE  [sshd] Unban 86.127.225.2
2022-06-28 11:40:30,745 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:40:30
2022-06-28 11:40:30,746 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:40:30
2022-06-28 11:41:05,200 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:05,201 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:05,202 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:05,201 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:05,403 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:05,404 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:06,005 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:06,006 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:06,006 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:06,008 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:06,008 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:06,007 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:41:05
2022-06-28 11:41:06,266 fail2ban.actions        [728]: NOTICE  [ssh] Ban 86.127.225.2
2022-06-28 11:41:06,522 fail2ban.actions        [728]: NOTICE  [sshd] Ban 86.127.225.2
2022-06-28 11:51:05,141 fail2ban.actions        [728]: NOTICE  [ssh] Unban 86.127.225.2
2022-06-28 11:51:05,379 fail2ban.actions        [728]: NOTICE  [sshd] Unban 86.127.225.2
2022-06-28 11:53:24,548 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:24,548 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:24,549 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:24,549 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:24,549 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:24,550 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:25,152 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:25,153 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:25,153 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:25,153 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:53:24
2022-06-28 11:53:25,355 fail2ban.filter         [728]: INFO    [ssh] Found 86.127.225.2 - 2022-06-28 11:53:25
2022-06-28 11:53:25,356 fail2ban.filter         [728]: INFO    [sshd] Found 86.127.225.2 - 2022-06-28 11:53:25
2022-06-28 11:53:25,383 fail2ban.actions        [728]: NOTICE  [ssh] Ban 86.127.225.2
2022-06-28 11:53:25,593 fail2ban.actions        [728]: NOTICE  [sshd] Ban 86.127.225.2
2022-06-28 12:03:26,278 fail2ban.actions        [728]: NOTICE  [ssh] Unban 86.127.225.2
2022-06-28 12:03:26,467 fail2ban.actions        [728]: NOTICE  [sshd] Unban 86.127.225.2
#/var/log/auth.log
...
Jun 28 11:40:35 lightstock-staging sshd[478015]: Accepted publickey for web from 86.127.225.2 port 53190 ssh2: RSA SHA256:ZRdkK....
Jun 28 11:40:40 lightstock-staging sshd[478126]: Received disconnect from 86.127.225.2 port 53190:11: disconnected by user
Jun 28 11:40:40 lightstock-staging sshd[478126]: Disconnected from user web 86.127.225.2 port 53190
Jun 28 11:41:05 lightstock-staging sshd[478164]: ROOT LOGIN REFUSED FROM 86.127.225.2 port 53203
Jun 28 11:41:05 lightstock-staging sshd[478164]: ROOT LOGIN REFUSED FROM 86.127.225.2 port 53203 [preauth]
Jun 28 11:41:05 lightstock-staging sshd[478164]: Connection closed by authenticating user root 86.127.225.2 port 53203 [preauth]
Jun 28 11:41:05 lightstock-staging sshd[478166]: ROOT LOGIN REFUSED FROM 86.127.225.2 port 53204
Jun 28 11:41:05 lightstock-staging sshd[478166]: ROOT LOGIN REFUSED FROM 86.127.225.2 port 53204 [preauth]
Jun 28 11:41:05 lightstock-staging sshd[478166]: Connection closed by authenticating user root 86.127.225.2 port 53204 [preauth]
Jun 28 11:51:47 lightstock-staging sshd[478242]: Accepted publickey for lightstock from 86.127.225.2 port 53260 ssh2: RSA SHA256:ZRdkK....
Jun 28 11:52:52 lightstock-staging sshd[478328]: Received disconnect from 86.127.225.2 port 53260:11: disconnected by user
Jun 28 11:52:52 lightstock-staging sshd[478328]: Disconnected from user lightstock 86.127.225.2 port 53260
Jun 28 11:53:24 lightstock-staging sshd[478893]: ROOT LOGIN REFUSED FROM 86.127.225.2 port 53274
Jun 28 11:53:24 lightstock-staging sshd[478893]: ROOT LOGIN REFUSED FROM 86.127.225.2 port 53274 [preauth]
Jun 28 11:53:24 lightstock-staging sshd[478893]: Connection closed by authenticating user root 86.127.225.2 port 53274 [preauth]
Jun 28 11:53:24 lightstock-staging sshd[478895]: ROOT LOGIN REFUSED FROM 86.127.225.2 port 53275
Jun 28 11:53:24 lightstock-staging sshd[478895]: ROOT LOGIN REFUSED FROM 86.127.225.2 port 53275 [preauth]
Jun 28 11:53:25 lightstock-staging sshd[478895]: Connection closed by authenticating user root 86.127.225.2 port 53275 [preauth]
Jun 28 12:07:01 lightstock-staging sshd[479735]: Accepted publickey for lightstock from 86.127.225.2 port 53442 ssh2: RSA SHA256:ZRdkK....

To be able to provision I ssh using admin user and added my IP address to ignoreip list in /etc/fail2ban/jail.local file then I restarted the fail2ban service using sudo fail2ban service restart. Add my new IP to ip_whitelist.

From what I can tell ipify_public_ip is getting my IP address and is automatically added to ignoreip list in /etc/fail2ban/jail.local file when I provision the server but my ISP has changed my IP Address and was different from the IP that provision the server initially.

3 Likes