与串行设备ASYNCIO蟒需要100％的CPU

问题描述：

当我从rfxcom python library运行这个小主：与串行设备ASYNCIO蟒需要100％的CPU

from asyncio import get_event_loop 
from rfxcom.transport import AsyncioTransport 

dev_name = '/dev/serial/by-id/usb-RFXCOM_RFXtrx433_A1XZI13O-if00-port0' 
loop = get_event_loop() 

def handler(packet): 
    print(packet.data) 

try: 
    rfxcom = AsyncioTransport(dev_name, loop, callback=handler) 
    loop.run_forever() 
finally: 
    loop.close()

我看到CPU使用率变得很HIGHT（约100％）。我不明白为什么：模块接收到的消息很少（每5秒〜1条消息），我认为当调用epoll_wait时，CPU应该闲置，等待下一个事件。

我公司推出的主要有蟒蛇CPROFILE，它显示了这一点：

In [4]: s.sort_stats('time', 'module').print_stats(50) 
Mon Jul 20 22:20:55 2015 rfxcom_profile.log 

    263629453 function calls (263628703 primitive calls) in 145.437 seconds 

    Ordered by: internal time, file name 
    List reduced from 857 to 50 due to restriction <50> 

    ncalls tottime percall cumtime percall filename:lineno(function) 
13178675 37.280 0.000 141.337 0.000 /usr/local/lib/python3.4/asyncio/base_events.py:1076(_run_once) 
13178675 31.114 0.000 53.230 0.000 /usr/local/lib/python3.4/selectors.py:415(select) 
13178674 15.115 0.000 32.253 0.000 /usr/local/lib/python3.4/asyncio/selector_events.py:479(_process_events) 
13178675 12.582 0.000 12.582 0.000 {method 'poll' of 'select.epoll' objects} 
13178699 11.462 0.000 17.138 0.000 /usr/local/lib/python3.4/asyncio/base_events.py:1058(_add_callback) 
13178732 6.397 0.000 11.397 0.000 /usr/local/lib/python3.4/asyncio/events.py:118(_run) 
26359349 4.872 0.000 4.872 0.000 {built-in method isinstance} 
     1 4.029 4.029 145.365 145.365 /usr/local/lib/python3.4/asyncio/base_events.py:267(run_forever) 
13178669 4.010 0.000 4.913 0.000 /home/bruno/src/DomoPyc/venv/lib/python3.4/site-packages/rfxcom-0.3.0-py3.4.egg/rfxcom/transport/asyncio.py:85(_writer)

所以前三个功能在过去的时间期限要求是python3.4/asyncio/base_events.py，python3.4/selectors.py和python3.4/asyncio/selector_events.py。

编辑：一个类似的运行时间命令给出：

time python -m cProfile -o rfxcom_profile.log rfxcom_profile.py 
real 2m24.548s 
user 2m19.892s 
sys  0m4.113s

有人能解释我为什么？

EDIT2：作为fonctions呼叫的数量是非常高的，我做的过程中的strace的，发现有上epoll_wait循环与2ms的超时值：

// many lines like this : 
epoll_wait(4, {{EPOLLOUT, {u32=7, u64=537553536922157063}}}, 2, -1) = 1

我在base_event._run_once中看到超时已计算，但我无法弄清楚。我不知道如何设置这个超时以降低CPU。

如果有人有线索...

谢谢你的回答。

它将大部分时间花在'select'上，这并不令人惊讶，因为这基本上是在事件之间进行的。在Unixy系统上，'time'命令可以显示进程是I/O限制还是CPU限制。它的输出将有助于诊断这个问题。 – Kevin

谢谢凯文，是的，我没有想到时间命令。我要编辑这个问题 –

答

我回答我的问题，因为它可能对别人有用。

在已经设置的环境变量PYTHONASYNCIODEBUG为1，有线条和线条状：

DEBUG:asyncio:poll took 0.006 ms: 1 events

在Rfxcom库有一个写入器机构与队列将数据推至串行设备。我的意图是我认为“asyncio，告诉我什么时候可以写，然后我会刷新写入队列”。因此就出现了这样一行：

self.loop.call_soon(self.loop.add_writer, self.dev.fd, self._writer)

self.dev是Serial类实例和self.dev.fd是串行文件描述符。

As the doc says“add_writer（fd，callback，* args）：开始观察文件描述符的写入可用性”。

我认为，一个串行设备总是可以写，所以我做了一个小脚本：

logger = logging.getLogger() 
logger.setLevel(logging.DEBUG) 

loop = get_event_loop() 

def writer_cb(): 
    logger.info("writer cb called") 

s = Serial('/dev/serial/by-id/usb-RFXCOM_RFXtrx433_A1XZI13O-if00-port0', 38400, timeout=1) 

loop.add_writer(s.fd, writer_cb) 
loop.run_forever()

，只见线循环不休，使CPU到100％：

DEBUG:asyncio:poll took 0.006 ms: 1 events 
INFO:root:writer cb called

与串行设备ASYNCIO蟒需要100％的CPU

相关推荐