search

chrysn / aiocoap

The Python CoAP library
Other
262 stars 119 forks source link

CPU usage anomaly #358

Open lixian2333 opened 4 days ago

lixian2333 commented 4 days ago

Hello everyone,

I used aiocoap to build a CoAP service, and after running on Docker for a period of time, the CPU usage exceeds 100%. Is this normal?

Python version: 3.10.14 (main, Jun 13 2024, 06:54:45) [GCC 10.2.1 20210110] aiocoap version: 0.4.9 Modules missing for subsystems: dtls: everything there oscore: missing cbor2, cryptography, filelock, ge25519 linkheader: everything there prettyprint: missing cbor2, pygments, cbor-diag ws: missing websockets Python platform: linux Default server transports: tinydtls:tcpserver:tcpclient:tlsserver:tlsclient:udp6 Selected server transports: tinydtls_server Default client transports: tinydtls:tcpclient:tlsclient:udp6 Selected client transports: tinydtls:tcpclient:tlsclient:udp6 SO_REUSEPORT available (default, selected): True, True

Docker stats: CONTAINER ID NAME CPU % MEM USAGE / LIMIT MEM % NET I/O BLOCK I/O PIDS e4d5a8826217 coap_server 108.43% 58.17MiB / 3.738GiB 1.52% 12.3MB / 8.9MB 553kB / 46.1MB 11

Resource： </.well-known/core>;ct="40",</beta/whoami>,</beta/notify/806599A5000C>;obs,</beta/notify/806599A500DC>;obs,</beta/notify/806599A50024>;obs,</beta/notify/806599A4FDCC>;obs,</beta/notify/806599A4FE00>;obs,</beta/notify/806599A500CC>;obs,</beta/notify/34B47253047C>;obs,</beta/notify/806599A4FE4C>;obs,</beta/notify/806599A4FE8C>;obs,</beta/notify/806599A4FDC8>;obs,</beta/notify/744DBDA1C490>;obs,</beta/notify/34B472530494>;obs,</beta/notify/806599A4FE94>;obs,</beta/notify/34B47253048C>;obs,</beta/notify/34B472530480>;obs,</beta/notify/DCDA0C1BA9DC>;obs,</beta/notify/9C9E6E8698D8>;obs,</beta/notify/806599A4FE58>;obs,https://christian.amsuess.com/tools/aiocoap/#version-0.4.9;rel="impl-info"

cProfile(1s): Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 15962 0.130 0.000 0.994 0.000 base_events.py:1832(_run_once) 50698 0.046 0.000 0.715 0.000 events.py:78(_run) 50698 0.067 0.000 0.669 0.000 {method 'run' of '_contextvars.Context' objects} 50634 0.109 0.000 0.491 0.000 tinydtls_server.py:149(_run_retransmissions) 25320 0.031 0.000 0.321 0.000 tasks.py:331(create_task) 25331 0.090 0.000 0.238 0.000 base_events.py:431(create_task) 50686 0.047 0.000 0.198 0.000 base_events.py:743(call_soon) 50687 0.062 0.000 0.142 0.000 base_events.py:772(_call_soon) 15962 0.022 0.000 0.096 0.000 selectors.py:452(select) 50700 0.062 0.000 0.071 0.000 events.py:31(init) 15962 0.062 0.000 0.062 0.000 {method 'poll' of 'select.epoll' objects} 50630 0.029 0.000 0.037 0.000 tasks.py:593(sleep) 25331 0.025 0.000 0.032 0.000 _weakrefset.py:86(add) 25331 0.031 0.000 0.031 0.000 {built-in method _asyncio.get_running_loop} 25330 0.017 0.000 0.023 0.000 _weakrefset.py:39(_remove) 25320 0.018 0.000 0.022 0.000 tasks.py:65(_set_task_name) 76032 0.016 0.000 0.016 0.000 base_events.py:513(_check_closed) 76065 0.015 0.000 0.015 0.000 base_events.py:1927(get_debug) 15975 0.007 0.000 0.012 0.000 base_events.py:696(time) 25320 0.012 0.000 0.012 0.000 init.py:9(py38args) 48024 0.011 0.000 0.011 0.000 {built-in method builtins.len} 50628 0.009 0.000 0.009 0.000 tasks.py:581(__sleep0) 50706 0.009 0.000 0.009 0.000 {method 'append' of 'collections.deque' objects} 15966 0.008 0.000 0.008 0.000 {built-in method builtins.max} 25318 0.007 0.000 0.007 0.000 {method 'checkRetransmit' of 'DTLSSocket.dtls.DTLS' objects} 50710 0.007 0.000 0.007 0.000 {method 'popleft' of 'collections.deque' objects} 25340 0.007 0.000 0.007 0.000 {method 'add' of 'set' objects} 6 0.000 0.000 0.007 0.001 pipe.py:196(wrapped) 6 0.000 0.000 0.007 0.001 protocol.py:381(_render_to_pipe) 6 0.000 0.000 0.007 0.001 resource.py:423(render_to_pipe) 5 0.000 0.000 0.006 0.001 _helper.py:56(render_to_pipe) 25331 0.006 0.000 0.006 0.000 {method 'discard' of 'set' objects} 25330 0.005 0.000 0.005 0.000 {built-in method time.time} 6 0.000 0.000 0.005 0.001 resource.py:136(render_to_pipe) 6 0.000 0.000 0.005 0.001 interfaces.py:326(_render_to_pipe) 15994 0.005 0.000 0.005 0.000 {built-in method time.monotonic} 14 0.000 0.000 0.005 0.000 init.py:1600(_log) 17 0.000 0.000 0.004 0.000 init.py:1455(debug) 15962 0.004 0.000 0.004 0.000 selector_events.py:600(_process_events) 4 0.000 0.000 0.004 0.001 selector_events.py:1021(_read_ready) 2 0.000 0.000 0.004 0.002 messagemanager.py:430(_send_initially) 4 0.000 0.000 0.004 0.001 tinydtls_server.py:186(datagram_received) 25320 0.004 0.000 0.004 0.000 {method 'set_name' of '_asyncio.Task' objects}

chrysn commented 4 days ago

I haven't seen such behavior yet. Is there a request that triggers it? what kinds of requests are being processed? Is DTLS in active use?

lixian2333 commented 4 days ago

I haven't seen such behavior yet. Is there a request that triggers it? what kinds of requests are being processed? Is DTLS in active use?

I checked the request logs and everything seems normal. When I cut off the server's network, even if no requests come in, the CPU usage does not decrease.

chrysn commented 4 days ago

How long has the server been running, what rough number of requests was it processing? (So far I'm far in the dark here, trying to get a rough impression in hopes to trigger an idea where to look.)