New issue 2900: High CPU usage on reading from socket during urllib.request https://bitbucket.org/pypy/pypy/issues/2900/high-cpu-usage-on-reading-from-socket
Noam Meltzer: The following code will result in 100% CPU usage on pypy3 version higher than 5.5. (with pypy3-5.5 and CPython it works properly) ```python import urllib.request import sys token = 'PUT_YOUR_TOKEN_HERE' url = 'https://api.telegram.org/bot{}/getUpdates'.format(token) req = urllib.request.Request(url, data=b'{}', headers={'Content-Type': 'application/json'}) while True: res = urllib.request.urlopen(req, timeout=100).read() print(res, file=sys.stderr) ``` The code is a client for a remote server and performs long-polling. Running strace shows that the socket is set as non-blocking and then improperly polled/read from. As you can see in strace output below, after creating the socket, `fcntl F_SETFL` is being called to set it non blocking. Following that a few other operations are performed and then the real problem begins: * `read()` is called, returning EAGAIN * `poll()` with argument `events=POLLIN|POLLOUT` is called, immediately returning as ready to write (but not read!) * `read()` is called, only to return EAGAIN. * the `poll()` & `read()` continued to be called in a loop yielding 100% cpu usage. ```strace 11191 socket(AF_INET, SOCK_STREAM|SOCK_CLOEXEC, IPPROTO_TCP) = 3<TCP:[180349]> 11191 fcntl(3<TCP:[180349]>, F_GETFL) = 0x2 (flags O_RDWR) 11191 fcntl(3<TCP:[180349]>, F_SETFL, O_RDWR|O_NONBLOCK) = 0 11191 connect(3<TCP:[180349]>, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("149.154.167.220")}, 16) = -1 EINPROGRESS (Operation now in progress) 11191 poll([{fd=3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, events=POLLOUT}], 1, 100000) = 1 ([{fd=3, revents=POLLOUT}]) 11191 getsockopt(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 11191 setsockopt(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, SOL_TCP, TCP_NODELAY, [1], 4) = 0 11191 getsockopt(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, SOL_SOCKET, SO_TYPE, [1], [4]) = 0 11191 fcntl(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) 11191 getpeername(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("149.154.167.220")}, [16]) = 0 11191 getpid() = 11191 11191 write(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, "<SNIP>", 517) = 517 11191 read(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, 0x11bf210, 7) = -1 EAGAIN (Resource temporarily unavailable) 11191 poll([{fd=3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, events=POLLIN|POLLOUT}], 1, 99999) = 1 ([{fd=3, revents=POLLOUT}]) 11191 read(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, 0x11bf210, 7) = -1 EAGAIN (Resource temporarily unavailable) 11191 poll([{fd=3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, events=POLLIN|POLLOUT}], 1, 99998) = 1 ([{fd=3, revents=POLLOUT}]) 11191 read(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, 0x11bf210, 7) = -1 EAGAIN (Resource temporarily unavailable) 11191 poll([{fd=3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, events=POLLIN|POLLOUT}], 1, 99998) = 1 ([{fd=3, revents=POLLOUT}]) 11191 read(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, 0x11bf210, 7) = -1 EAGAIN (Resource temporarily unavailable) 11191 poll([{fd=3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, events=POLLIN|POLLOUT}], 1, 99997) = 1 ([{fd=3, revents=POLLOUT}]) 11191 read(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, 0x11bf210, 7) = -1 EAGAIN (Resource temporarily unavailable) ... many many more poll() & read() ... 11191 poll([{fd=3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, events=POLLIN|POLLOUT}], 1, 99902) = 1 ([{fd=3, revents=POLLIN|POLLOUT}]) 11191 mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1e0c7bd000 11191 brk(NULL) = 0x11ea000 11191 brk(0x121b000) = 0x121b000 11191 read(3<TCP:[10.31.96.137:43498->149.154.167.220:443]>, "\26\3\3\0B\2\0", 7) = 7 ... >From here on behaviour seems normal ... ``` Intuitively I would say that the socket should not be set non-blocking on the first place (the whole request is synchronous), but if this is the normal behaviour then `poll()` should be handled more delicately (Only `POLLIN` should be set for `events). NOTES: 1. I was having difficulty simulating this behaviour with a local server, so it might also be related to network delays. 2. This report follows the original bug as reported here: https://github.com/python-telegram-bot/python-telegram-bot/issues/1194 3. If you'd like to recreate the bug against Telegram servers and don't want to bother on creating, I can supply a temporary token, so feel free to contact me for that. _______________________________________________ pypy-issue mailing list pypy-issue@python.org https://mail.python.org/mailman/listinfo/pypy-issue
