1

I have an old server on CentOS 5, with cPanel installed, hosted on Amazon AWS EC2:

uname -a
Linux 2.6.32-573.22.1.el6.x86_64 #1 SMP Wed Mar 23 03:35:39 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

It wasn't touched for a very long time. Today, suddenly, it's not able to make outgoing connections on port 443:

curl -v https://google.com
* About to connect() to google.com port 443 (#0)
*   Trying 142.250.217.78... Connection timed out
*   Trying 2607:f8b0:400a:80b::200e... Failed to connect to 2607:f8b0:400a:80b::200e: Network is unreachable
* Success
* couldn't connect to host
* Closing connection #0
curl: (7) Failed to connect to 2607:f8b0:400a:80b::200e: Network is unreachable

while the connections to port 80 go through:

curl -v http://google.com                                                                                                                                                        ⏎
* About to connect() to google.com port 80 (#0)
*   Trying 142.251.211.238... connected
* Connected to google.com (142.251.211.238) port 80 (#0)
> GET / HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.44 zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Host: google.com
> Accept: */*
> 
< HTTP/1.1 301 Moved Permanently
< Location: http://www.google.com/
< Content-Type: text/html; charset=UTF-8
< Date: Fri, 25 Nov 2022 21:24:03 GMT
< Expires: Sun, 25 Dec 2022 21:24:03 GMT
< Cache-Control: public, max-age=2592000
< Server: gws
< Content-Length: 219
< X-XSS-Protection: 0
< X-Frame-Options: SAMEORIGIN
< 
<HTML><HEAD><meta http-equiv="content-type" content="text/html;charset=utf-8">
<TITLE>301 Moved</TITLE></HEAD><BODY>
<H1>301 Moved</H1>
The document has moved
<A HREF="http://www.google.com/">here</A>.
</BODY></HTML>
* Connection #0 to host google.com left intact
* Closing connection #0

I've cleaned iptables to ensure that's they're not a problem:

iptables -L
Chain INPUT (policy ACCEPT)
target     prot opt source               destination         

Chain FORWARD (policy ACCEPT)
target     prot opt source               destination         

Chain OUTPUT (policy ACCEPT)
target     prot opt source               destination

The only relevant note in /var/log/messages I can find, during the moment when problems started to occur, logs when datadog agent starts to fail at 11:25:

ov 25 11:04:50 xxx dd.dogstatsd[6842]: INFO (dogstatsd.py:276): Flush #944863: flushed 25 metrics, 0 events, and 0 service check runs
Nov 25 11:05:00 xxx dd.dogstatsd[6842]: INFO (dogstatsd.py:276): Flush #944864: flushed 25 metrics, 0 events, and 0 service check runs
Nov 25 11:05:05 xxx dd.forwarder[6840]: INFO (transaction.py:190): No transaction to flush during flush #3145520
Nov 25 11:05:10 xxx dd.dogstatsd[6842]: INFO (dogstatsd.py:276): Flush #944865: flushed 25 metrics, 0 events, and 0 service check runs
Nov 25 11:06:00 xxx dd.forwarder[6840]: INFO (transaction.py:190): No transaction to flush during flush #3145540
Nov 25 11:07:00 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 1 transaction during flush #3145560
Nov 25 11:07:29 xxx dd.collector[6857]: INFO (collector.py:571): Finished run #491350. Collection time: 4.23s. Emit time: 0.02s
Nov 25 11:08:05 xxx dd.forwarder[6840]: INFO (transaction.py:190): No transaction to flush during flush #3145580
Nov 25 11:09:03 xxx pure-ftpd: ([email protected]) [INFO] New connection from 127.0.0.1
Nov 25 11:09:03 xxx pure-ftpd: ([email protected]) [INFO] __cpanel__service__auth__ftpd__xxx is now logged in
Nov 25 11:09:03 xxx pure-ftpd: ([email protected]) [INFO] Logout.
Nov 25 11:09:10 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 1 transaction during flush #3145600
Nov 25 11:10:05 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 2 transactions during flush #3145620
Nov 25 11:10:43 xxx dd.collector[6857]: INFO (collector.py:571): Finished run #491360. Collection time: 4.12s. Emit time: 0.02s
Nov 25 11:11:02 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 1 transaction during flush #3145640
Nov 25 11:12:05 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 3 transactions during flush #3145660
Nov 25 11:13:20 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 3 transactions during flush #3145680
Nov 25 11:13:55 xxx dd.collector[6857]: INFO (collector.py:571): Finished run #491370. Collection time: 4.23s. Emit time: 0.02s
Nov 25 11:14:07 xxx pure-ftpd: ([email protected]) [INFO] New connection from 127.0.0.1
Nov 25 11:14:07 xxx pure-ftpd: ([email protected]) [INFO] __cpanel__service__auth__ftpd__xxx is now logged in
Nov 25 11:14:07 xxx pure-ftpd: ([email protected]) [INFO] Logout.
Nov 25 11:14:45 xxx dd.forwarder[6840]: INFO (transaction.py:190): No transaction to flush during flush #3145700
Nov 25 11:16:00 xxx dd.dogstatsd[6842]: INFO (dogstatsd.py:276): Flush #944930: flushed 25 metrics, 0 events, and 0 service check runs
Nov 25 11:16:09 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 1 transaction during flush #3145720
Nov 25 11:16:10 xxx dd.dogstatsd[6842]: INFO (dogstatsd.py:276): Flush #944931: flushed 25 metrics, 0 events, and 0 service check runs
Nov 25 11:16:20 xxx dd.dogstatsd[6842]: INFO (dogstatsd.py:276): Flush #944932: flushed 26 metrics, 0 events, and 0 service check runs
Nov 25 11:16:30 xxx dd.dogstatsd[6842]: INFO (dogstatsd.py:276): Flush #944933: flushed 25 metrics, 0 events, and 0 service check runs
Nov 25 11:16:40 xxx dd.dogstatsd[6842]: INFO (dogstatsd.py:276): Flush #944934: flushed 25 metrics, 0 events, and 0 service check runs
Nov 25 11:16:50 xxx dd.dogstatsd[6842]: INFO (dogstatsd.py:276): Flush #944935: flushed 25 metrics, 0 events, and 0 service check runs
Nov 25 11:17:07 xxx dd.collector[6857]: INFO (collector.py:571): Finished run #491380. Collection time: 4.12s. Emit time: 0.02s
Nov 25 11:17:26 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 1 transaction during flush #3145740
Nov 25 11:18:30 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 1 transaction during flush #3145760
Nov 25 11:18:32 xxx dhclient[1080]: DHCPREQUEST on eth0 to 10.0.0.1 port 67 (xid=0x24b5d86f)
Nov 25 11:18:32 xxx dhclient[1080]: DHCPACK from 10.0.0.1 (xid=0x24b5d86f)
Nov 25 11:18:34 xxx dhclient[1080]: bound to 10.0.0.247 -- renewal in 1642 seconds.
Nov 25 11:19:30 xxx dd.forwarder[6840]: INFO (transaction.py:190): No transaction to flush during flush #3145780
Nov 25 11:20:08 xxx pure-ftpd: ([email protected]) [INFO] New connection from 127.0.0.1
Nov 25 11:20:08 xxx pure-ftpd: ([email protected]) [INFO] __cpanel__service__auth__ftpd__xxx is now logged in
Nov 25 11:20:08 xxx pure-ftpd: ([email protected]) [INFO] Logout.
Nov 25 11:20:19 xxx dd.collector[6857]: INFO (collector.py:571): Finished run #491390. Collection time: 4.22s. Emit time: 0.02s
Nov 25 11:20:30 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 1 transaction during flush #3145800
Nov 25 11:21:36 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 1 transaction during flush #3145820
Nov 25 11:22:26 xxx auditd[1137]: Audit daemon rotating log files
Nov 25 11:22:35 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 2 transactions during flush #3145840
Nov 25 11:23:31 xxx dd.forwarder[6840]: INFO (transaction.py:177): Flushing 1 transaction during flush #3145860
Nov 25 11:23:31 xxx dd.collector[6857]: INFO (collector.py:571): Finished run #491400. Collection time: 4.13s. Emit time: 0.02s
Nov 25 11:24:40 xxx dd.forwarder[6840]: INFO (transaction.py:190): No transaction to flush during flush #3145880
Nov 25 11:25:07 xxx pure-ftpd: ([email protected]) [INFO] New connection from 127.0.0.1
Nov 25 11:25:07 xxx pure-ftpd: ([email protected]) [INFO] __cpanel__service__auth__ftpd__xxx is now logged in
Nov 25 11:25:07 xxx pure-ftpd: ([email protected]) [INFO] Logout.
Nov 25 11:25:47 xxx dd.forwarder[6840]: ERROR (ddagent.py:282): Response: HTTPResponse(_body=None,buffer=None,code=599,effective_url='https://5-32-8-app.agent.datadoghq.com/intake/?api_key=*************************55166',error=HTTPError('HTTP 599: Timeout',),headers={},reason='Unknown',request=<tornado.httpclient.HTTPRequest object at 0x7f0612cfdad0>,request_time=20.000658988952637,time_info={})
Nov 25 11:25:47 xxx dd.forwarder[6840]: WARNING (transaction.py:268): Transaction 2419202 in error (1 error), it will be replayed after 2022-11-25 11:26:07
Nov 25 11:26:10 xxx dd.forwarder[6840]: ERROR (ddagent.py:282): Response: HTTPResponse(_body=None,buffer=None,code=599,effective_url='https://5-32-8-app.agent.datadoghq.com/api/v1/check_run/?api_key=*************************55166',error=HTTPError('HTTP 599: Timeout',),headers={},reason='Unknown',request=<tornado.httpclient.HTTPRequest object at 0x7f0612d04d50>,request_time=20.00121808052063,time_info={})
Nov 25 11:26:10 xxx dd.forwarder[6840]: WARNING (transaction.py:268): Transaction 2419209 in error (1 error), it will be replayed after 2022-11-25 11:26:30
Nov 25 11:26:10 xxx dd.forwarder[6840]: WARNING (transaction.py:212): Flush 3145896 is taking more than 10s, stopping it
Nov 25 11:26:31 xxx dd.forwarder[6840]: ERROR (ddagent.py:282): Response: HTTPResponse(_body=None,buffer=None,code=599,effective_url='https://5-32-8-app.agent.datadoghq.com/api/v1/series/?api_key=*************************55166',error=HTTPError('HTTP 599: Timeout',),headers={},reason='Unknown',request=<tornado.httpclient.HTTPRequest object at 0x7f0613138e50>,request_time=20.00036597251892,time_info={})
Nov 25 11:26:31 xxx dd.forwarder[6840]: WARNING (transaction.py:268): Transaction 2419215 in error (1 error), it will be replayed after 2022-11-25 11:26:51
Nov 25 11:26:31 xxx dd.forwarder[6840]: WARNING (transaction.py:212): Flush 3145897 is taking more than 10s, stopping it
Nov 25 11:26:43 xxx dd.collector[6857]: INFO (collector.py:571): Finished run #491410. Collection time: 4.24s. Emit time: 0.02s
Nov 25 11:26:51 xxx dd.forwarder[6840]: ERROR (ddagent.py:282): Response: HTTPResponse(_body=None,buffer=None,code=599,effective_url='https://5-32-8-app.agent.datadoghq.com/api/v1/series/?api_key=*************************55166',error=HTTPError('HTTP 599: Timeout',),headers={},reason='Unknown',request=<tornado.httpclient.HTTPRequest object at 0x7f0612cfd950>,request_time=20.00032901763916,time_info={})

No AWS configuration regarding security and networking has been changed. It seems that all HTTPS connections time out, hanging in SYN_SENT state..

Any ideas are very much appreciated.

Regards

synweap15
  • 121
  • 4
  • When you're on AWS you also need to look at AWS constructs such as security groups and network ACLs. For example, your EC2 instance may be in a security group that allows outgoing port 80 but not port 443. It's impossible to diagnose this from inside the EC2 VM., – Stephen Harris Nov 25 '22 at 21:41
  • Your example of an https attempt returned an IPv6 address from DNS and couldn't connect to the IPv6 address. Your example of an http attempt returned an IPv4 address from DNS and could connect. What happens when you select IPv4 only via `curl -4 -v https://google.com/` ? – Sotto Voce Nov 25 '22 at 23:34
  • I've got the same problem. Did you find a solution? – Gloire Apr 25 '23 at 09:52
  • 1
    @Gloire please see my own accepted answer – synweap15 Apr 28 '23 at 15:48

1 Answers1

1

The problem was that the outbound connectivity got suspended due to (falsely claimed) DMCA notice. The primary owner of the account didn't monitor his mailbox where Amazon has sent a DMCA takedown notice forwarded from a third party. Due to lack of response in 14 (or 30, don't recall) days, the port block was enforced by the AWS staff.

This was very baffling.

After getting in touch with AWS and fixing the underlying issue, the connectivity was restored.

synweap15
  • 121
  • 4