Skip to content
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.

Sign up for GitHub

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

Jump to bottom

Amplify Agent inactive after start. #76

Open
PietroLiuzzo opened this issue Jan 18, 2022 · 24 comments
Open

Amplify Agent inactive after start. #76

PietroLiuzzo opened this issue Jan 18, 2022 · 24 comments

Comments

@PietroLiuzzo
Copy link

Hi! I am trying to re-install Amplify on Ubuntu 18.04.6 LTS (GNU/Linux 4.15.0-166-generic x86_64).
I have now done several times the installation procedure but to no avail, I get the following

sudo service amplify-agent start
pietro@betamasaheft2:~$ sudo service amplify-agent status
● amplify-agent.service - NGINX Amplify Agent
   Loaded: loaded (/lib/systemd/system/amplify-agent.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Tue 2022-01-18 06:56:18 CET; 4s ago
     Docs: https://amplify.nginx.com/docs/
  Process: 48092 ExecStop=/etc/init.d/amplify-agent stop (code=exited, status=0/SUCCESS)
  Process: 48023 ExecStart=/etc/init.d/amplify-agent start (code=exited, status=0/SUCCESS)
 Main PID: 48088 (code=exited, status=0/SUCCESS)

Jan 18 06:56:16 betamasaheft2 systemd[1]: Starting NGINX Amplify Agent...
Jan 18 06:56:18 betamasaheft2 systemd[1]: amplify-agent.service: Can't open PID file /var/run/amplify-agent/amplify-agent.pid (yet?) after start: No such file or directory
Jan 18 06:56:18 betamasaheft2 systemd[1]: Started NGINX Amplify Agent.

The log reports

2022-01-18 07:29:38,706 [48757] MainThread performing configtest check...
2022-01-18 07:29:39,667 [48757] MainThread [76e8f1f06e1838f2c4753542488c020d] post https://receiver.amplify.nginx.com:443/1.4/45243040b0ec78e52d221cc425f6a439/agent/ 200 10 5 0.960
2022-01-18 07:29:39,668 [48757] MainThread config file is ok!
2022-01-18 07:29:39,731 [48778] supervisor failed POST "https://receiver.amplify.nginx.com:443/1.4/45243040b0ec78e52d221cc425f6a439/agent/", exception: "('This operation would block forever', <Hub at 0x7f187cfd3638 epoll default pending=0 ref=0 fileno=3 resolver=<gevent.resolver_thread.Resolver at 0x7f187a3acbe0 pool=<ThreadPool at 0x7f187a3acc18 1/1/10>> threadpool=<ThreadPool at 0x7f187a3acc18 1/1/10>>)"
2022-01-18 07:29:39,732 [48778] supervisor [None] post https://receiver.amplify.nginx.com:443/1.4/45243040b0ec78e52d221cc425f6a439/agent/ 500 100 0 0.005
2022-01-18 07:29:39,732 [48778] supervisor could not connect to cloud
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/amplify/agent/supervisor.py", line 356, in talk_to_cloud
    context.http_client.post('agent/', data=root_object)
  File "/usr/lib/python3/dist-packages/amplify/agent/common/util/http.py", line 128, in post
    return self.make_request(url, 'post', data=data, timeout=timeout, json=json)
  File "/usr/lib/python3/dist-packages/amplify/agent/common/util/http.py", line 110, in make_request
    raise e
  File "/usr/lib/python3/dist-packages/amplify/agent/common/util/http.py", line 99, in make_request
    proxies=self.proxies
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 567, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 520, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 630, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 440, in send
    timeout=timeout
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 601, in urlopen
    chunked=chunked)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 346, in _make_request
    self._validate_conn(conn)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 852, in _validate_conn
    conn.connect()
  File "/usr/lib/python3/dist-packages/urllib3/connection.py", line 298, in connect
    conn = self._new_conn()
  File "/usr/lib/python3/dist-packages/urllib3/connection.py", line 144, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/usr/lib/python3/dist-packages/urllib3/util/connection.py", line 60, in create_connection
    for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
  File "/usr/lib/python3/dist-packages/gevent/_socketcommon.py", line 288, in getaddrinfo
    return get_hub().resolver.getaddrinfo(host, port, family, type, proto, flags)
  File "/usr/lib/python3/dist-packages/gevent/resolver_thread.py", line 65, in getaddrinfo
    return self.pool.apply(_socket.getaddrinfo, args, kwargs)
  File "/usr/lib/python3/dist-packages/gevent/pool.py", line 325, in apply
    return self.spawn(func, *args, **kwds).get()
  File "/usr/lib/python3/dist-packages/gevent/event.py", line 382, in get
    self._wait_core(timeout, ())
  File "/usr/lib/python3/dist-packages/gevent/event.py", line 106, in _wait_core
    result = self.hub.switch()
  File "/usr/lib/python3/dist-packages/gevent/hub.py", line 630, in switch
    return RawGreenlet.switch(self)
gevent.hub.LoopExit: ('This operation would block forever', <Hub at 0x7f187cfd3638 epoll default pending=0 ref=0 fileno=3 resolver=<gevent.resolver_thread.Resolver at 0x7f187a3acbe0 pool=<ThreadP$
2022-01-18 07:29:39,737 [48778] supervisor uncaught exception during run time
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/amplify/agent/supervisor.py", line 356, in talk_to_cloud
    context.http_client.post('agent/', data=root_object)
  File "/usr/lib/python3/dist-packages/amplify/agent/common/util/http.py", line 128, in post
    return self.make_request(url, 'post', data=data, timeout=timeout, json=json)
  File "/usr/lib/python3/dist-packages/amplify/agent/common/util/http.py", line 110, in make_request

Can anyone suggest how to solve this issue and get amplify back to work?
@defanator
Copy link
Contributor

@PietroLiuzzo based on the logs it seems like there's no network reachability from your instance to Amplify receiver endpoint (https://receiver.amplify.nginx.com/) - could you please check the following:

  1. Which IP are you getting on resolving receiver.amplify.nginx.com?
  2. Are you able to ping that IP? (ICMP should be currently open for all endpoints)
  3. Are you able to open a connection to 443/tcp port from your instance to that IP?

@PietroLiuzzo
Copy link
Author

Thanks for your reply!

I am not sure about ICMP. I have tried the following and I am not able to get an IP back. If you can tel me how you would check I would be happy to run what you suggest

curl --head receiver.amplify.nginx.com
HTTP/1.1 301 Moved Permanently
Server: nginx
Date: Tue, 18 Jan 2022 08:21:46 GMT
Content-Type: text/html
Content-Length: 162
Connection: keep-alive
Location: http://receiver.amplify.nginx.com/
X-Amplify-ID: e4de2b62b36809ac34a7654dd5dd5724

pietro@betamasaheft2:~$ curl --head https://receiver.amplify.nginx.com
HTTP/1.1 404 Not Found
Server: nginx
Date: Tue, 18 Jan 2022 08:22:06 GMT
Content-Type: text/html
Content-Length: 146
Connection: keep-alive
X-Amplify-ID: 00d1daf130667f9221c7947d65856367

It worked perfectly until yesterday. Then I reinstalled, in order to change the API key used to that of a colleague taking over the supervision. It did not work and even going back to my own API key is giving this error.

@defanator
Copy link
Contributor

@PietroLiuzzo could you please show an output of the following commands:

lsb_release -a
dpkg -s nginx-amplify-agent
curl -vi https://receiver.amplify.nginx.com/1.4/45243040b0ec78e52d221cc425f6a439/agent/

TIA!

@PietroLiuzzo
Copy link
Author

lsb_release -a

No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 18.04.6 LTS
Release: 18.04
Codename: bionic

dpkg -s nginx-amplify-agent

Package: nginx-amplify-agent
Status: install ok installed
Priority: optional
Section: python
Installed-Size: 6121
Maintainer: Andrei Belov [email protected]
Architecture: amd64
Version: 1.8.0-1bionic
Depends: python3 (<< 3.7), python3 (>= 3.6), python3:any (>= 3.3.2-2~), python3-setproctitle, python3-greenlet, python3-gevent, python3-requests, python3-ujson, python3-netifaces, python3-pymysql, lsb-release, adduser
Conffiles:
/etc/amplify-agent/agent.conf.default c4831c94e00e9de9cf24bd14a040287c
/etc/init.d/amplify-agent cac1488d95443fbc0b5f0eeb5da0d250
/etc/logrotate.d/amplify-agent da238aa3d910729211814d1de3e9ed4c
Description: Agent for NGINX Amplify monitoring platform
The NGINX Amplify Agent is a small, Python application that provides
system and NGINX metric collection. It is part of NGINX Amplify -
the monitoring and configuration assistance service for NGINX.
.
This package installs and runs NGINX Amplify Agent daemon.
.
See http://nginx.com/amplify for more information
Homepage: https://github.com/nginxinc/nginx-amplify-agent

curl -vi https://receiver.amplify.nginx.com/1.4/45243040b0ec78e52d221cc425f6a439/agent/

Trying 35.155.143.94...

  • TCP_NODELAY set
  • Connected to receiver.amplify.nginx.com (35.155.143.94) port 443 (#0)
  • ALPN, offering h2
  • ALPN, offering http/1.1
  • successfully set certificate verify locations:
  • CAfile: /etc/ssl/certs/ca-certificates.crt
    CApath: /etc/ssl/certs
  • TLSv1.3 (OUT), TLS handshake, Client hello (1):
  • TLSv1.3 (IN), TLS handshake, Server hello (2):
  • TLSv1.2 (IN), TLS handshake, Certificate (11):
  • TLSv1.2 (IN), TLS handshake, Server key exchange (12):
  • TLSv1.2 (IN), TLS handshake, Server finished (14):
  • TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
  • TLSv1.2 (OUT), TLS change cipher, Client hello (1):
  • TLSv1.2 (OUT), TLS handshake, Finished (20):
  • TLSv1.2 (IN), TLS handshake, Finished (20):
  • SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
  • ALPN, server accepted to use http/1.1
  • Server certificate:
  • subject: CN=receiver.amplify.nginx.com
  • start date: Jan 13 21:05:25 2022 GMT
  • expire date: Apr 13 21:05:24 2022 GMT
  • subjectAltName: host "receiver.amplify.nginx.com" matched cert's "receiver.amplify.nginx.com"
  • issuer: C=US; O=Let's Encrypt; CN=R3
  • SSL certificate verify ok.

GET /1.4/45243040b0ec78e52d221cc425f6a439/agent/ HTTP/1.1
Host: receiver.amplify.nginx.com
User-Agent: curl/7.58.0
Accept: /

< HTTP/1.1 405 METHOD NOT ALLOWED
HTTP/1.1 405 METHOD NOT ALLOWED
< Server: nginx
Server: nginx
< Date: Tue, 18 Jan 2022 08:44:49 GMT
Date: Tue, 18 Jan 2022 08:44:49 GMT
< Content-Type: application/json
Content-Type: application/json
< Content-Length: 64
Content-Length: 64
< Connection: keep-alive
Connection: keep-alive
< Allow: OPTIONS, POST
Allow: OPTIONS, POST
< X-Amplify-ID: a856e7244e972bb71f2b4806403e632e
X-Amplify-ID: a856e7244e972bb71f2b4806403e632e

<
{"message": "The method is not allowed for the requested URL."}

  • Connection #0 to host receiver.amplify.nginx.com left intact
pietro@betamasaheft2:~$ getent ahosts receiver.amplify.nginx.com
35.155.143.94   STREAM receiver.amplify.nginx.com
35.155.143.94   DGRAM  
35.155.143.94   RAW 

pietro@betamasaheft2:~$ ping 35.155.143.94
PING 35.155.143.94 (35.155.143.94) 56(84) bytes of data.
```

@PietroLiuzzo
Copy link
Author

I am not even sure what TIA! means.... sorry!

@defanator
Copy link
Contributor

@PietroLiuzzo no worries (TIA is just "thanks in advance"). Could you please change the api_url parameter in /etc/amplify-agent/agent.conf in the following way:

api_url = https://35.155.143.94:443/1.4

and restart the agent? (This is not a permanent solution - we're just trying to understand whether there are any issues with your local resolver as initial logs pointed to that thing.)

@PietroLiuzzo
Copy link
Author

I have done that

[cloud]
api_url = https://35.155.143.94:443/1.4

saved and run sudo service amplify-agent start response is

Job for amplify-agent.service failed because the control process exited with error code.
See "systemctl status amplify-agent.service" and "journalctl -xe" for details.

pietro@betamasaheft2:~$ sudo service amplify-agent status
● amplify-agent.service - NGINX Amplify Agent
   Loaded: loaded (/lib/systemd/system/amplify-agent.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Tue 2022-01-18 11:23:27 CET; 1min 51s ago
     Docs: https://amplify.nginx.com/docs/
  Process: 49238 ExecStop=/etc/init.d/amplify-agent stop (code=exited, status=0/SUCCESS)
  Process: 52017 ExecStart=/etc/init.d/amplify-agent start (code=exited, status=1/FAILURE)
 Main PID: 49234 (code=exited, status=0/SUCCESS)

Jan 18 11:23:27 betamasaheft2 amplify-agent[52017]:   File "/usr/lib/python3.6/configparser.py", line 697, in read
Jan 18 11:23:27 betamasaheft2 amplify-agent[52017]:     self._read(fp, filename)
Jan 18 11:23:27 betamasaheft2 amplify-agent[52017]:   File "/usr/lib/python3.6/configparser.py", line 1080, in _read
Jan 18 11:23:27 betamasaheft2 amplify-agent[52017]:     raise MissingSectionHeaderError(fpname, lineno, line)
Jan 18 11:23:27 betamasaheft2 amplify-agent[52017]: configparser.MissingSectionHeaderError: File contains no section headers.
Jan 18 11:23:27 betamasaheft2 amplify-agent[52017]: file: '/etc/amplify-agent/agent.conf', line: 1
Jan 18 11:23:27 betamasaheft2 amplify-agent[52017]: 'api_url = https://35.155.143.94:443/1.4[credentials]\n'
Jan 18 11:23:27 betamasaheft2 systemd[1]: amplify-agent.service: Control process exited, code=exited status=1
Jan 18 11:23:27 betamasaheft2 systemd[1]: amplify-agent.service: Failed with result 'exit-code'.
Jan 18 11:23:27 betamasaheft2 systemd[1]: Failed to start NGINX Amplify Agent.

@PietroLiuzzo
Copy link
Author

TIA!

@defanator
Copy link
Contributor

@PietroLiuzzo it seems like you've broken agent.conf somehow. Please try to restore it manually from original default one (https://github.com/nginxinc/nginx-amplify-agent/blob/master/etc/agent.conf.default), or by running install script once again, then change api_url to the value mentioned above, and try to start amplify-agent service once again.

Please note that agent may overwrite api_url automatically with the one provided by receivers once it communicates over established API connection, so you have to modify your agent.conf when agent is stopped.

@PietroLiuzzo
Copy link
Author

PietroLiuzzo commented Jan 18, 2022 •
edited
Loading

sorry, I have done this running the install script once again

Launching amplify-agent ...
 All done.

pietro@betamasaheft2:~$ sudo service amplify-agent stop
pietro@betamasaheft2:~$ sudo nano /etc/amplify-agent/agent.conf

Here I have changed api_url = https://35.155.143.94:443/1.4

then

pietro@betamasaheft2:~$ sudo service amplify-agent start
pietro@betamasaheft2:~$ sudo service amplify-agent status
● amplify-agent.service - NGINX Amplify Agent
   Loaded: loaded (/lib/systemd/system/amplify-agent.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Tue 2022-01-18 11:58:07 CET; 6s ago
     Docs: https://amplify.nginx.com/docs/
  Process: 53533 ExecStop=/etc/init.d/amplify-agent stop (code=exited, status=0/SUCCESS)
  Process: 53462 ExecStart=/etc/init.d/amplify-agent start (code=exited, status=0/SUCCESS)
 Main PID: 53530 (code=exited, status=0/SUCCESS)

Jan 18 11:58:05 betamasaheft2 systemd[1]: Starting NGINX Amplify Agent...
Jan 18 11:58:07 betamasaheft2 systemd[1]: amplify-agent.service: Can't open PID file /var/run/amplify-agent/amplify-agent.pid (yet?) after start: No such file or director
Jan 18 11:58:07 betamasaheft2 systemd[1]: Started NGINX Amplify Agent.
```

@defanator
Copy link
Contributor

@PietroLiuzzo what's in agent logs? (/var/log/amplify-agent/agent.log)

@PietroLiuzzo
Copy link
Author 

2022-01-18 11:58:06,440 [53509] MainThread performing configtest check...
2022-01-18 11:58:07,215 [53509] MainThread [d992d96d5dbe209ac115e8fab3366a60] post https://35.155.143.94:443/1.4/45243040b0ec78e52d221cc425f6a439/agent/ 200 10 5 0.775
2022-01-18 11:58:07,216 [53509] MainThread config file is ok!
2022-01-18 11:58:07,277 [53530] supervisor failed POST "https://35.155.143.94:443/1.4/45243040b0ec78e52d221cc425f6a439/agent/", exception: "('This operation would block forever', <Hub at 0x7f8cb8975$
2022-01-18 11:58:07,277 [53530] supervisor [None] post https://35.155.143.94:443/1.4/45243040b0ec78e52d221cc425f6a439/agent/ 500 100 0 0.005
2022-01-18 11:58:07,278 [53530] supervisor could not connect to cloud
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/amplify/agent/supervisor.py", line 356, in talk_to_cloud
    context.http_client.post('agent/', data=root_object)
  File "/usr/lib/python3/dist-packages/amplify/agent/common/util/http.py", line 128, in post
    return self.make_request(url, 'post', data=data, timeout=timeout, json=json)
  File "/usr/lib/python3/dist-packages/amplify/agent/common/util/http.py", line 110, in make_request
    raise e
  File "/usr/lib/python3/dist-packages/amplify/agent/common/util/http.py", line 99, in make_request
    proxies=self.proxies
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 567, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 520, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/lib/python3/dist-packages/requests/sessions.py", line 630, in send
    r = adapter.send(request, **kwargs)
  File "/usr/lib/python3/dist-packages/requests/adapters.py", line 440, in send
    timeout=timeout
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 601, in urlopen
    chunked=chunked)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 346, in _make_request
    self._validate_conn(conn)
  File "/usr/lib/python3/dist-packages/urllib3/connectionpool.py", line 852, in _validate_conn
    conn.connect()
  File "/usr/lib/python3/dist-packages/urllib3/connection.py", line 298, in connect
    conn = self._new_conn()
  File "/usr/lib/python3/dist-packages/urllib3/connection.py", line 144, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/usr/lib/python3/dist-packages/urllib3/util/connection.py", line 60, in create_connection
    for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
  File "/usr/lib/python3/dist-packages/gevent/_socketcommon.py", line 288, in getaddrinfo
    return get_hub().resolver.getaddrinfo(host, port, family, type, proto, flags)
  File "/usr/lib/python3/dist-packages/gevent/resolver_thread.py", line 65, in getaddrinfo
    return self.pool.apply(_socket.getaddrinfo, args, kwargs)
  File "/usr/lib/python3/dist-packages/gevent/pool.py", line 325, in apply
 .......
.......
    return RawGreenlet.switch(self)
gevent.hub.LoopExit: ('This operation would block forever', <Hub at 0x7f8cb8975638 epoll default pending=0 ref=0 fileno=3 resolver=<gevent.resolver_thread.Resolver at 0x7f8cb5d56be0 pool=<ThreadPool$

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/amplify/agent/main.py", line 147, in run
    daemon_runner.do_action()
  File "/usr/lib/python3/dist-packages/amplify/daemon/runner.py", line 283, in do_action
    func(self)
  File "/usr/lib/python3/dist-packages/amplify/daemon/runner.py", line 202, in _start
    self.app.run()
  File "/usr/lib/python3/dist-packages/amplify/agent/supervisor.py", line 220, in run
    self.talk_to_cloud(initial=True)
  File "/usr/lib/python3/dist-packages/amplify/agent/supervisor.py", line 381, in talk_to_cloud
    raise AmplifyCriticalException()
amplify.agent.common.errors.AmplifyCriticalException: (message=None, payload=None)

@PietroLiuzzo
Copy link
Author

looks to me like the first one, but with the IP instead of the url :)

@defanator
Copy link
Contributor

@PietroLiuzzo thanks for doing that. You mentioned that you were re-installing the agent (https://github.com/nginxinc/nginx-amplify-agent/issues/215#issue-1106529879) - does it mean you may have running another (older) one before? If so, could you please try to figure out which version was running, and how it was installed?

Also, an output of the following commands would help us to check some theory:

sudo python3 -m pip list | egrep -i "gevent|greenlet|requests"
dpkg -l | egrep -i "gevent|greenlet|requests"

@PietroLiuzzo
Copy link
Author

I had to install pip, then I run the two commands and here are the results.

sudo python3 -m pip list | egrep -i "gevent|greenlet|requests"
DEPRECATION: The default format will switch to columns in the future. You can use --format=(legacy|columns) (or define a format=(legacy|columns) in your pip.conf under the [list] section) to disable this warning.
gevent (1.2.2)
greenlet (0.4.12)
requests (2.18.4)
requests-unixsocket (0.1.5)

 dpkg -l | egrep -i "gevent|greenlet|requests"
ii  python3-gevent                         1.2.2-2                                         amd64        gevent is a coroutine-based Python networking library
ii  python3-greenlet                       0.4.12-2                                        amd64        Lightweight in-process concurrent programming (python3)
ii  python3-requests                       2.18.4-2ubuntu0.1                               all          elegant and simple HTTP library for Python3, built for human beings
ii  python3-requests-unixsocket            0.1.5-3                                         all          Use requests to talk HTTP via a UNIX domain socket - Python 3.x

@PietroLiuzzo
Copy link
Author

I installed amplify on 14 April 2021 following the standard easy procedure with success on this server, and then never needed to touch it again. I did regular updates and the first time a issue comes up is now.

@PietroLiuzzo
Copy link
Author

(no major setup changes occurred on the server since)

@defanator
Copy link
Contributor

@PietroLiuzzo thanks for providing additional details. So far it seems like your particular system doesn't work well with new Amplify agent version 1.8.0 running under Python 3. This is a recent update. In April 2021 you were getting older one (1.7.0) which was running under Python 2.

You may want to downgrade an agent to check this assumption, though I would encourage to spin up a fresh 18.04 or 20.04 instance / server (if this is acceptable) and try to re-install latest agent. We use 18.04 in our build and testing pipelines, and we weren't noticing anything similar to your issue before. The one difference I noticed is that we are using 5.4 kernel while your installation is still on 4.15, but I've just tested new agent's behavior on Ubuntu 18.04 with older 4.15 kernel and it works fine.

Just for the record - in order to downgrade an agent from 1.8.0 to lower one, you'll need to edit your /etc/apt/sources.list.d/nginx-amplify.list and put the following in there:

deb https://packages.amplify.nginx.com/ubuntu/ bionic amplify-agent

After the change, run the following:

dpkg -P nginx-amplify-agent
rm -rf /var/cache/apt/archives/
apt-get update
apt-get install nginx-amplify-agent

Then check that /etc/amplify-agent/agent.conf contains your valid API key, and start the agent service by running service amplify-agent start.

(The latest Python 2 based version for Ubuntu 18.04 should be 1.7.0-5~bionic - you can check this with dpkg -s nginx-amplify-agent.)

I'm going to leave this one open just in case if we'll get other similar reports.

@PietroLiuzzo
Copy link
Author

Thanks! this solution worked well and I now see metrics again!

@defanator
Copy link
Contributor

@PietroLiuzzo could you please also show the output of the following (on the same system):

python3 --version
dpkg -s python3
dpkg -s python3.6

Thanks!

@PietroLiuzzo
Copy link
Author 


pietro@betamasaheft2:/var/cache/apt/archives$ python3 --version
Python 3.6.9
pietro@betamasaheft2:/var/cache/apt/archives$ dpkg -s python3
Package: python3
Status: install ok installed
Priority: important
Section: python
Installed-Size: 187
Maintainer: Ubuntu Developers <[email protected]>
Architecture: amd64
Multi-Arch: allowed
Source: python3-defaults
Version: 3.6.7-1~18.04
Replaces: python3-minimal (<< 3.1.2-2)
Provides: python3-profiler
Depends: python3.6 (>= 3.6.7-1~), libpython3-stdlib (= 3.6.7-1~18.04)
Pre-Depends: python3-minimal (= 3.6.7-1~18.04)
Suggests: python3-doc (>= 3.6.7-1~18.04), python3-tk (>= 3.6.7-1~), python3-venv (>= 3.6.7-1~18.04)
Description: interactive high-level object-oriented language (default python3 version)
 Python, the high-level, interactive object oriented language,
 includes an extensive class library with lots of goodies for
 network programming, system administration, sounds and graphics.
 .
 This package is a dependency package, which depends on Debian's default
 Python 3 version (currently v3.6).
Homepage: https://www.python.org/
Cnf-Extra-Commands: python
Cnf-Priority-Bonus: 5
Original-Maintainer: Matthias Klose <[email protected]>
pietro@betamasaheft2:/var/cache/apt/archives$ dpkg -s python3.6
Package: python3.6
Status: install ok installed
Priority: important
Section: python
Installed-Size: 329
Maintainer: Ubuntu Developers <[email protected]>
Architecture: amd64
Multi-Arch: allowed
Version: 3.6.9-1~18.04ubuntu1.6
Depends: python3.6-minimal (= 3.6.9-1~18.04ubuntu1.6), libpython3.6-stdlib (= 3.6.9-1~18.04ubuntu1.6), mime-support
Suggests: python3.6-venv, python3.6-doc, binutils
Breaks: python3-all (<< 3.6.5~rc1-1), python3-dev (<< 3.6.5~rc1-1), python3-venv (<< 3.6.5-2)
Description: Interactive high-level object-oriented language (version 3.6)
 Python is a high-level, interactive, object-oriented language. Its 3.6 version
 includes an extensive class library with lots of goodies for
 network programming, system administration, sounds and graphics.
Original-Maintainer: Matthias Klose <[email protected]>
pietro@betamasaheft2:/var/cache/apt/archives$

@ademaro
Copy link

ademaro commented Jan 23, 2022

I have a very similar problem, an agent was installed on a fresh system, but it works for a couple of minutes (at https://amplify.nginx.com/) but then goes red. On rare occasions, the nginx graphs show data for those couple of minutes, but the system graphs (like php) are always blank. It never shows CPU or memory load.

err

Some additional information:

# ❯❯❯ uname -a
Linux admel 5.10.0-11-amd64 nginxinc/nginx-amplify-agent-priv#1 SMP Debian 5.10.92-1 (2022-01-18) x86_64 GNU/Linux

# ❯❯❯ python3 --version
Python 3.9.2

# ❯❯❯ python3 -m pip list | egrep -i "gevent|greenlet|requests"
gevent              20.9.0
greenlet            0.4.17
requests            2.25.1

# ❯❯❯ dpkg -l | egrep -i "gevent|greenlet|requests"
ii  python3-gevent                   20.9.0-2                                        amd64        gevent is a coroutine-based Python networking library
ii  python3-greenlet                 0.4.17-1+b1                                     amd64        Lightweight in-process concurrent programming (python3)
ii  python3-requests                 2.25.1+dfsg-2                                   all          elegant and simple HTTP library for Python3, built for human beings

# ❯❯❯ lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 11 (bullseye)
Release:        11
Codename:       bullseye

# ❯❯❯ dpkg -s nginx-amplify-agent
Package: nginx-amplify-agent
Status: install ok installed
Priority: optional
Section: python
Installed-Size: 1236
Maintainer: Andrei Belov <[email protected]>
Architecture: amd64
Version: 1.8.0-1~bullseye
Depends: python3:any, python3-daemon, python3-psutil, python3-setproctitle, python3-greenlet, python3-gevent, python3-requests, python3-ujson, python3-netifaces, python3-pymysql, lsb-release, adduser
Conffiles:
 /etc/amplify-agent/agent.conf.default c4831c94e00e9de9cf24bd14a040287c
 /etc/init.d/amplify-agent cac1488d95443fbc0b5f0eeb5da0d250
 /etc/logrotate.d/amplify-agent da238aa3d910729211814d1de3e9ed4c
Description: Agent for NGINX Amplify monitoring platform
 The NGINX Amplify Agent is a small, Python application that provides
 system and NGINX metric collection. It is part of NGINX Amplify -
 the monitoring and configuration assistance service for NGINX.
 .
 This package installs and runs NGINX Amplify Agent daemon.
 .
 See http://nginx.com/amplify for more information
Homepage: https://github.com/nginxinc/nginx-amplify-agent

# ❯❯❯ curl -vi https://receiver.amplify.nginx.com/1.4/45243040b0ec78e52d221cc425f6a439/agent/
*   Trying 52.36.73.123:443...
* Connected to receiver.amplify.nginx.com (52.36.73.123) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*  CAfile: /etc/ssl/certs/ca-certificates.crt
*  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* ALPN, server accepted to use http/1.1
* Server certificate:
*  subject: CN=receiver.amplify.nginx.com
*  start date: Jan 13 21:05:25 2022 GMT
*  expire date: Apr 13 21:05:24 2022 GMT
*  subjectAltName: host "receiver.amplify.nginx.com" matched cert's "receiver.amplify.nginx.com"
*  issuer: C=US; O=Let's Encrypt; CN=R3
*  SSL certificate verify ok.
> GET /1.4/45243040b0ec78e52d221cc425f6a439/agent/ HTTP/1.1
> Host: receiver.amplify.nginx.com
> User-Agent: curl/7.74.0
> Accept: */*
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 405 METHOD NOT ALLOWED
HTTP/1.1 405 METHOD NOT ALLOWED
< Server: nginx
Server: nginx
< Date: Sun, 23 Jan 2022 17:45:19 GMT
Date: Sun, 23 Jan 2022 17:45:19 GMT
< Content-Type: application/json
Content-Type: application/json
< Content-Length: 64
Content-Length: 64
< Connection: keep-alive
Connection: keep-alive
< Allow: POST, OPTIONS
Allow: POST, OPTIONS
< X-Amplify-ID: 4fb7eaeb146c21f917180f351b39fc7d
X-Amplify-ID: 4fb7eaeb146c21f917180f351b39fc7d

<
{"message": "The method is not allowed for the requested URL."}
* Connection #0 to host receiver.amplify.nginx.com left intact

log with debug info:

2022-01-23 20:46:34,483 [988030] MainThread performing configtest check...                                                                                                          [1068/4514]
2022-01-23 20:46:35,372 [988030] MainThread {'config': {'cloud': {'talk_interval': 120.0, 'api_url': 'https://receiver.amplify.nginx.com:443/1.4', 'push_interval': 60.0, 'api_timeout': 10.0}, 'containers': {'phpfpm_pool': {'poll_intervals': {'metrics': 20.0, 'meta': 60.0, 'discover': 10.0}}, 'phpfpm': {'poll_intervals': {'metrics': 20.0, 'meta': 60.0, 'discover': 10.0}}, 'plus':
{'poll_intervals': {'metrics': 20.0, 'meta': 60.0, 'discover': 10.0}}, 'nginx': {'parse_delay': 60.0, 'max_test_duration': 30.0, 'poll_intervals': {'metrics': 20.0, 'configs': 20.0, 'meta': 6
0.0, 'logs': 10.0, 'discover': 10.0}, 'upload_config': True, 'run_test': True, 'upload_ssl': True}, 'system': {'poll_intervals': {'metrics': 20.0, 'meta': 60.0, 'discover': 10.0}}}}, 'objects
': [], 'messages': [], 'versions': {'current': '1.4.1', 'old': '1.1.0', 'obsolete': '0.44'}, 'capabilities': {'configurator': True, 'mysql': True, 'php-fpm': True}}
2022-01-23 20:46:35,373 [988030] MainThread [eba686ce81ddc535960cee8322e025cd] post https://35.155.143.94:443/1.4/87970a009520cfdd316a71344aebfbaa/agent/ 200 10 5 0.888
2022-01-23 20:46:35,377 [988030] MainThread config file is ok!
2022-01-23 20:46:37,412 [988094] supervisor {'config': {'cloud': {'talk_interval': 120.0, 'api_url': 'https://receiver.amplify.nginx.com:443/1.4', 'push_interval': 60.0, 'api_timeout': 10.0},
 'containers': {'phpfpm_pool': {'poll_intervals': {'metrics': 20.0, 'meta': 60.0, 'discover': 10.0}}, 'phpfpm': {'poll_intervals': {'metrics': 20.0, 'meta': 60.0, 'discover': 10.0}}, 'plus':
{'poll_intervals': {'metrics': 20.0, 'meta': 60.0, 'discover': 10.0}}, 'nginx': {'parse_delay': 60.0, 'max_test_duration': 30.0, 'poll_intervals': {'metrics': 20.0, 'configs': 20.0, 'meta': 6
0.0, 'logs': 10.0, 'discover': 10.0}, 'upload_config': True, 'run_test': True, 'upload_ssl': True}, 'system': {'poll_intervals': {'metrics': 20.0, 'meta': 60.0, 'discover': 10.0}}}}, 'objects
': [], 'messages': [], 'versions': {'current': '1.4.1', 'old': '1.1.0', 'obsolete': '0.44'}, 'capabilities': {'configurator': True, 'mysql': True, 'php-fpm': True}}
2022-01-23 20:46:37,413 [988094] supervisor [ec6b04c67b53c677b8f6bdb6d4e94ce0] post https://35.155.143.94:443/1.4/87970a009520cfdd316a71344aebfbaa/agent/ 200 80 5 0.916
2022-01-23 20:46:37,417 [988094] supervisor app config has changed. now running with: {'agent': {'launchers': ''},
 'cloud': {'api_timeout': 10.0,
           'api_url': 'https://35.155.143.94:443/1.4',
           'gzip': 6,
           'push_interval': 60.0,
           'talk_interval': 120.0,
           'verify_ssl_cert': False},
 'containers': {'nginx': {'max_test_duration': 30.0,
                          'parse_delay': 60.0,
                          'poll_intervals': {'configs': 20.0,
                                             'discover': 10.0,
                                             'logs': 10.0,
                                             'meta': 60.0,
                                             'metrics': 20.0},
                          'run_test': True,
                          'upload_config': True,
                          'upload_ssl': True},
                'phpfpm': {'poll_intervals': {'discover': 10.0,
                                              'meta': 60.0,
                                              'metrics': 20.0}},
                'phpfpm_pool': {'poll_intervals': {'discover': 10.0,
                                                   'meta': 60.0,
                                                   'metrics': 20.0}},
                'plus': {'poll_intervals': {'discover': 10.0,
                                            'meta': 60.0,                                                                                                                                                                                  'metrics': 20.0}},
                'system': {'poll_intervals': {'discover': 10.0,
                                              'meta': 60.0,
                                              'metrics': 20.0}}},
 'credentials': {'api_key': '87970a009520cfdd316a71344aebfbaa',
                 'hostname': 'admel',
                 'imagename': '',
                 'store_uuid': 'False',
                 'uuid': '55b49d19677d53449ded80f32459cf29'},                                                                                                                                   'daemon': {'cpu_limit': 10.0,
            'cpu_sleep': 0.2,
            'pid': '/var/run/amplify-agent/amplify-agent.pid'},
 'extensions': {'mysql': 'False', 'phpfpm': 'True'},
 'formatter_simpleFormatter': {'datefmt': '',
                               'format': '%(asctime)s [%(process)d] '
                                         '%(threadName)s %(message)s'},
 'formatters': {'keys': 'simpleFormatter'},
 'handler_agent-default': {'args': "('/var/log/amplify-agent/agent.log', 'a', "
                                   'None, 1)',
                           'class': 'logging.handlers.WatchedFileHandler',
                           'formatter': 'simpleFormatter',
                           'level': 'DEBUG'},
 'handler_devnull': {'args': "('/dev/null',)",
                     'class': 'logging.handlers.WatchedFileHandler',
                     'formatter': 'simpleFormatter',
                     'level': 'DEBUG'},
 'handler_root': {'args': "('/dev/null',)",
                  'class': 'logging.handlers.WatchedFileHandler',
                  'formatter': 'simpleFormatter',
                  'level': 'DEBUG'},
 'handlers': {'keys': 'root,devnull,agent-default'},
 'listener_syslog-default': {'address': ''},
 'listeners': {'keys': 'syslog-default'},
 'logger_agent-default': {'formatter': 'simpleFormatter',
                          'handlers': 'agent-default',
                          'level': 'DEBUG',
                          'propagate': '0',
                          'qualname': 'agent-default'},
 'logger_devnull': {'formatter': 'simpleFormatter',
                    'handlers': 'devnull',
                    'level': 'DEBUG',
                    'propagate': '0',
                    'qualname': 'devnull'},
 'logger_root': {'formatter': 'simpleFormatter',
                 'handlers': 'root',
                 'level': 'DEBUG',
                 'propagate': '0',
                 'qualname': 'root'},
 'loggers': {'keys': 'root,devnull,agent-default'},
 'mysql': {'password': 'j3qq4-h7h2v-2hch4',
           'remote': 'False',
           'unix_socket': '/var/run/mysqld/mysqld.sock',
           'user': 'amplify-agent'},
 'nginx': {'configfile': '/etc/nginx/nginx.conf',
           'exclude_logs': '/var/log/nginx/*-piwik.log',
           'user': 'www-data'},
 'proxies': {'https': ''}}
2022-01-23 20:46:37,422 [988094] supervisor loaded "system" object manager from <class 'amplify.agent.managers.system.SystemManager'>
2022-01-23 20:46:37,438 [988094] supervisor loaded "nginx" object manager from <class 'amplify.agent.managers.nginx.NginxManager'>
2022-01-23 20:46:37,452 [988094] supervisor loaded "status" object manager from <class 'amplify.agent.managers.status.StatusManager'>
2022-01-23 20:46:37,452 [988094] supervisor loaded "api" object manager from <class 'amplify.agent.managers.api.ApiManager'>
2022-01-23 20:46:37,456 [988094] supervisor ignored "abstract" module during ext scan
2022-01-23 20:46:37,456 [988094] supervisor ignored "mysql" module during ext scan
2022-01-23 20:46:37,481 [988094] supervisor loaded "phpfpm" object manager from <class 'amplify.ext.phpfpm.managers.master.PHPFPMManager'>
2022-01-23 20:46:37,483 [988094] supervisor loaded "phpfpm_pool" object manager from <class 'amplify.ext.phpfpm.managers.pool.PHPFPMPoolManager'>
2022-01-23 20:46:37,485 [988094] supervisor started "<bound method AbstractManager.start of <amplify.agent.managers.bridge.Bridge object at 0x7f523592ed60>>"
2022-01-23 20:46:42,654 [988094] supervisor
2022-01-23 20:46:42,655 [988094] supervisor [None] get http://169.254.169.254/latest/meta-data/instance-id 500 10 0 0.108
2022-01-23 20:46:42,760 [988094] supervisor
2022-01-23 20:46:42,760 [988094] supervisor [None] get http://169.254.169.254/latest/meta-data/hostname 500 10 0 0.104
2022-01-23 20:46:42,865 [988094] supervisor
2022-01-23 20:46:42,865 [988094] supervisor [None] get http://169.254.169.254/latest/meta-data/local-hostname 500 10 0 0.104
2022-01-23 20:46:42,970 [988094] supervisor
2022-01-23 20:46:42,970 [988094] supervisor [None] get http://169.254.169.254/latest/meta-data/public-hostname 500 10 0 0.104
2022-01-23 20:46:43,076 [988094] supervisor
2022-01-23 20:46:43,077 [988094] supervisor [None] get http://169.254.169.254/latest/meta-data/ami-id 500 10 0 0.105
2022-01-23 20:46:43,181 [988094] supervisor
2022-01-23 20:46:43,182 [988094] supervisor [None] get http://169.254.169.254/latest/meta-data/local-ipv4 500 10 0 0.104
2022-01-23 20:46:43,286 [988094] supervisor
2022-01-23 20:46:43,287 [988094] supervisor [None] get http://169.254.169.254/latest/meta-data/public-keys 500 10 0 0.105
2022-01-23 20:46:43,390 [988094] supervisor
2022-01-23 20:46:43,391 [988094] supervisor [None] get http://169.254.169.254/latest/meta-data/public-ipv4 500 10 0 0.103
2022-01-23 20:46:43,496 [988094] supervisor
2022-01-23 20:46:43,497 [988094] supervisor [None] get http://169.254.169.254/latest/meta-data/reservation-id 500 10 0 0.105
2022-01-23 20:46:43,520 [988094] supervisor "system" object registered with ObjectsTank (id: 1, name: system @ admel)
2022-01-23 20:46:43,520 [988094] supervisor system objects: ['3fa6c10bab13f04db1e7a2fc81b59463d2ea9a805c34588a5d2a13d202f16133']
2022-01-23 20:46:43,521 [988094] supervisor agent started, version=1.8.0-1 pid=988094 uuid=55b49d19677d53449ded80f32459cf29 hostname=admel
2022-01-23 20:46:43,521 [988094] supervisor starting object "system" 3fa6c10bab13f04db1e7a2fc81b59463d2ea9a805c34588a5d2a13d202f16133
2022-01-23 20:46:43,521 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.system.meta.DebianSystemMetaCollector object at 0x7f523593dac0>>"
2022-01-23 20:46:43,521 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.system.metrics.DebianSystemMetricsCollector object at 0x7f52358d1670>>"
2022-01-23 20:46:43,626 [988094] supervisor ps nginx output: [' 946509       1 nginx: master process /usr/sbin/nginx -c /etc/nginx/nginx.conf', ' 950112  946509 nginx: worker process', '']
2022-01-23 20:46:43,656 [988094] sys_metrics 3fa6c10bab13f04db1e7a2fc81b59463d2ea9a805c34588a5d2a13d202f16133 collect in 0.103
2022-01-23 20:46:43,743 [988094] supervisor found 16 files for /etc/nginx/nginx.conf
2022-01-23 20:46:43,743 [988094] supervisor found 6 directories for /etc/nginx/nginx.conf
2022-01-23 20:46:43,743 [988094] supervisor parsing full tree of /etc/nginx/nginx.conf
2022-01-23 20:46:43,784 [988094] supervisor parsed log formats, access logs, and error logs:
log formats: {
    "main2": "$remote_addr - $remote_user [$time_local] \"$request\" $status $body_bytes_sent \"$http_referer\" \"$http_user_agent\" \"$http_x_forwarded_for\"",
    "main_ext": "$remote_addr - $remote_user [$time_local] \"$request\" $status $body_bytes_sent \"$http_referer\" \"$http_user_agent\" \"$http_x_forwarded_for\" \"$host\" sn=\"$server_name\"
 rt=$request_time ua=\"$upstream_addr\" us=\"$upstream_status\" ut=\"$upstream_response_time\" ul=\"$upstream_response_length\" cs=$upstream_cache_status",
    "piwik": "{\"ip\": \"$remote_addr\",\"host\": \"$host\",\"path\": \"$request_uri\",\"status\": \"$status\",\"referrer\": \"$http_referer\",\"user_agent\": \"$http_user_agent\",\"length\":
 $bytes_sent,\"generation_time_milli\": $request_time,\"date\": \"$time_iso8601\"}"
}
access logs: {
    "/var/log/nginx/access.log": {
        "log_format": "main_ext",
        "permissions": "0o666",
        "readable": true
    },
    "/var/log/nginx/default.access.log": {
        "log_format": "main_ext",
        "permissions": "0o666",
        "readable": true
    },
    ...
}
error logs: {
    "/var/log/nginx/error.log": {
        "log_level": "warn",
        "permissions": "0o666",
        "readable": true
    },
   ...
}
2022-01-23 20:46:43,844 [988094] sys_meta 3fa6c10bab13f04db1e7a2fc81b59463d2ea9a805c34588a5d2a13d202f16133 collect in 0.316
2022-01-23 20:46:43,956 [988094] supervisor ssl certificate found /etc/ssl/domains/XXX/full.pem
2022-01-23 20:46:44,132 [988094] supervisor ssl analysis took 0.176 seconds for /etc/ssl/domains/XXX/full.pem
2022-01-23 20:46:44,293 [988094] supervisor running /usr/sbin/nginx -t -c /etc/nginx/nginx.conf
2022-01-23 20:46:44,334 [988094] supervisor 041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7 config parse on startup in 0.603
2022-01-23 20:46:44,345 [988094] supervisor Active connections: 2
server accepts handled requests
 579 579 571
Reading: 0 Writing: 1 Waiting: 1

2022-01-23 20:46:44,346 [988094] supervisor [None] get http://127.0.0.1:80/nginx_status 200 10 103 0.010
2022-01-23 20:46:44,396 [988094] supervisor "nginx" object registered with ObjectsTank (id: 2, name: nginx 1.21.5 @ admel)
2022-01-23 20:46:44,397 [988094] supervisor nginx objects: ['041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7']
2022-01-23 20:46:44,397 [988094] supervisor starting object "nginx" 041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7
2022-01-23 20:46:44,397 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.config.NginxConfigCollector object at 0x7f52358d1220>>"
2022-01-23 20:46:44,397 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.meta.DebianNginxMetaCollector object at 0x7f523593df40>>"
2022-01-23 20:46:44,398 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.metrics.DebianNginxMetricsCollector object at 0x7f52358d1c10>>"
2022-01-23 20:46:44,398 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.accesslog.NginxAccessLogsCollector object at 0x7f5235837070>>"
2022-01-23 20:46:44,398 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.accesslog.NginxAccessLogsCollector object at 0x7f5235837250>>"
2022-01-23 20:46:44,398 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.accesslog.NginxAccessLogsCollector object at 0x7f5235837d30>>"
2022-01-23 20:46:44,398 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.accesslog.NginxAccessLogsCollector object at 0x7f5235837e20>>"
2022-01-23 20:46:44,398 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.accesslog.NginxAccessLogsCollector object at 0x7f5235837fd0>>"
2022-01-23 20:46:44,399 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.accesslog.NginxAccessLogsCollector object at 0x7f52357eb0d0>>"
2022-01-23 20:46:44,399 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.accesslog.NginxAccessLogsCollector object at 0x7f52357eb1f0>>"
2022-01-23 20:46:44,399 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.accesslog.NginxAccessLogsCollector object at 0x7f52357eb310>>"
2022-01-23 20:46:44,399 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.accesslog.NginxAccessLogsCollector object at 0x7f52357eb430>>"
2022-01-23 20:46:44,399 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.errorlog.NginxErrorLogsCollector object at 0x7f52357eb550>>"
2022-01-23 20:46:44,400 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.errorlog.NginxErrorLogsCollector object at 0x7f52357eb640>>"
2022-01-23 20:46:44,400 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.errorlog.NginxErrorLogsCollector object at 0x7f52357eb730>>"
2022-01-23 20:46:44,400 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.errorlog.NginxErrorLogsCollector object at 0x7f52357eb820>>"
2022-01-23 20:46:44,400 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.errorlog.NginxErrorLogsCollector object at 0x7f52357eb910>>"
2022-01-23 20:46:44,400 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.errorlog.NginxErrorLogsCollector object at 0x7f52357eba00>>"
2022-01-23 20:46:44,400 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.agent.collectors.nginx.errorlog.NginxErrorLogsCollector object at 0x7f52357ebaf0>>"
2022-01-23 20:46:44,401 [988094] supervisor status objects: []
2022-01-23 20:46:44,401 [988094] supervisor api objects: []
2022-01-23 20:46:44,414 [988094] nginx_config 041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7 collect in 0.004
2022-01-23 20:46:44,448 [988094] nginx_alog 041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7 processed 0 lines from file:/var/log/nginx/access.log
2022-01-23 20:46:44,449 [988094] nginx_alog 041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7 collect in 0.001
2022-01-23 20:46:44,460 [988094] nginx_alog 041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7 processed 0 lines from file:/var/log/nginx/default.access.log
2022-01-23 20:46:44,460 [988094] nginx_alog
...
2022-01-23 20:46:44,521 [988094] supervisor ps php-fpm output: [' 909989       1 php-fpm: master process (/etc/php/8.1/fpm/php-fpm.conf)', ' 909991  909989 php-fpm: pool www', ' 909992  90998
9 php-fpm: pool www', '']
2022-01-23 20:46:44,527 [988094] supervisor "phpfpm" object registered with ObjectsTank (id: 3, name: phpfpm master @ admel)
2022-01-23 20:46:44,527 [988094] supervisor phpfpm objects: ['b1ed9d4341c9a886dd5679aeca5e76bd41087fc25c8b9b64d321a19fc1d97f09']
2022-01-23 20:46:44,528 [988094] supervisor starting object "phpfpm" b1ed9d4341c9a886dd5679aeca5e76bd41087fc25c8b9b64d321a19fc1d97f09
2022-01-23 20:46:44,528 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.ext.phpfpm.collectors.master.meta.PHPFPMMetaCollector object at 0x7f52357ebd30>>"
2022-01-23 20:46:44,528 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.ext.phpfpm.collectors.master.metrics.PHPFPMMetricsCollector object at 0x7f52357ebc10>>"
2022-01-23 20:46:44,529 [988094] supervisor parsing phpfpm conf "/etc/php/8.1/fpm/php-fpm.conf"
2022-01-23 20:46:44,538 [988094] supervisor finished parse of "/etc/php/8.1/fpm/php-fpm.conf" in 0.00
2022-01-23 20:46:44,540 [988094] supervisor "phpfpm_pool" object registered with ObjectsTank (id: 4, name: phpfpm www @ admel)
2022-01-23 20:46:44,540 [988094] supervisor phpfpm_pool objects: ['2b668c3a6e270a4fd348865ed4a2a110ae85a8d14f44270ebe6d6333a8349923']
2022-01-23 20:46:44,540 [988094] supervisor starting object "phpfpm_pool" 2b668c3a6e270a4fd348865ed4a2a110ae85a8d14f44270ebe6d6333a8349923
2022-01-23 20:46:44,540 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.ext.phpfpm.collectors.pool.meta.PHPFPMPoolMetaCollector object at 0x7f523585be50>>"
2022-01-23 20:46:44,541 [988094] supervisor started "<bound method AbstractCollector.run of <amplify.ext.phpfpm.collectors.pool.metrics.PHPFPMPoolMetricsCollector object at 0x7f523585be20>>"
2022-01-23 20:46:44,570 [988094] phpfpm_metrics b1ed9d4341c9a886dd5679aeca5e76bd41087fc25c8b9b64d321a19fc1d97f09 collect in 0.002
2022-01-23 20:46:44,586 [988094] phpfpm_pool_meta 2b668c3a6e270a4fd348865ed4a2a110ae85a8d14f44270ebe6d6333a8349923 collect in 0.014
2022-01-23 20:46:44,604 [988094] phpfpm_pool_metrics 2b668c3a6e270a4fd348865ed4a2a110ae85a8d14f44270ebe6d6333a8349923 collect in 0.016
2022-01-23 20:46:44,620 [988094] nginx_metrics Active connections: 2
server accepts handled requests
 579 579 572
Reading: 0 Writing: 1 Waiting: 1

2022-01-23 20:46:44,620 [988094] nginx_metrics [None] get http://127.0.0.1:80/nginx_status 200 10 103 0.185
2022-01-23 20:46:44,626 [988094] nginx_metrics 041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7 collect in 0.192
2022-01-23 20:46:44,903 [988094] phpfpm_meta failed to find php-fpm bin path, last attempt: "ls -la /proc/909992/exe" failed due to AmplifySubprocessError
2022-01-23 20:46:44,904 [988094] phpfpm_meta additional info:
NoneType: None
2022-01-23 20:46:44,906 [988094] phpfpm_meta b1ed9d4341c9a886dd5679aeca5e76bd41087fc25c8b9b64d321a19fc1d97f09 collect in 0.360
2022-01-23 20:46:44,919 [988094] nginx_meta 041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7 collect in 0.504
2022-01-23 20:46:49,547 [988094] supervisor system objects: ['3fa6c10bab13f04db1e7a2fc81b59463d2ea9a805c34588a5d2a13d202f16133']
2022-01-23 20:46:49,587 [988094] supervisor ps nginx output: [' 946509       1 nginx: master process /usr/sbin/nginx -c /etc/nginx/nginx.conf', ' 950112  946509 nginx: worker process', '']
2022-01-23 20:46:49,610 [988094] supervisor nginx objects: ['041fb1af9c07151f767134189f2854da35c9a57fc48d405931b8c2f04097b4b7']
2022-01-23 20:46:49,611 [988094] supervisor status objects: []
2022-01-23 20:46:49,611 [988094] supervisor api objects: []
2022-01-23 20:46:49,646 [988094] supervisor ps php-fpm output: [' 909989       1 php-fpm: master process (/etc/php/8.1/fpm/php-fpm.conf)', ' 909991  909989 php-fpm: pool www', ' 909992  90998
9 php-fpm: pool www', '']
2022-01-23 20:46:49,646 [988094] supervisor phpfpm objects: ['b1ed9d4341c9a886dd5679aeca5e76bd41087fc25c8b9b64d321a19fc1d97f09']
2022-01-23 20:46:49,647 [988094] supervisor phpfpm_pool objects: ['2b668c3a6e270a4fd348865ed4a2a110ae85a8d14f44270ebe6d6333a8349923']

I don't want to roll back to the old version, is there any chance they can fix it for python3?

@defanator
Copy link
Contributor

@ademaro could you please enable debug logging in the agent, and share full log for like 5 minutes after start? Are you seeing a message similar to this one: https://github.com/nginxinc/nginx-amplify-agent/issues/216#issuecomment-1016648877 ?

@ademaro
Copy link

ademaro commented Feb 3, 2022

@defanator its already with debug logging:

[handler_devnull]
class = logging.handlers.WatchedFileHandler
level = DEBUG
formatter = simpleFormatter
args = ('/dev/null',)

[logger_root]
level = DEBUG
handlers = root
qualname = root
formatter = simpleFormatter
propagate = 0

[handler_root]
class = logging.handlers.WatchedFileHandler
level = DEBUG
formatter = simpleFormatter
args = ('/dev/null',)

[logger_agent-default]
level = DEBUG
qualname = agent-default
handlers = agent-default
formatter = simpleFormatter
propagate = 0

[handler_agent-default]
class = logging.handlers.WatchedFileHandler
level = DEBUG
formatter = simpleFormatter
args = ('/var/log/amplify-agent/agent.log', 'a', None, 1)

Full log here: https://paste.c-net.org/TraitsNotch

@defanator defanator transferred this issue from another repository Aug 19, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@ademaro @PietroLiuzzo @defanator