Encountered FileNotFoundError error when using reverse proxy plugin

[Unintendedz]

Hi everyone, I'm new to proxy.py, I tried running a Docker image using command docker run -it -p 80:80 --rm abhinavsingh/proxy.py:latest --port 80 --hostname 0.0.0.0 --log-level d --enable-reverse-proxy --plugins proxy.plugin.ReverseProxyPlugin on server.

Then I accessed this reverse proxy through http://myserver/get.

It worked fine the first time but I found there is a error in the console afterwards

root@server:~# docker run -it -p 80:80 --rm abhinavsingh/proxy.py:latest --port 80 --hostname 0.0.0.0 --log-level d --enable-reverse-proxy --plugins proxy.plugin.ReverseProxyPlugin
2023-04-29 13:32:11,762 - pid:1 [I] plugins.load:85 - Loaded plugin proxy.http.proxy.HttpProxyPlugin
2023-04-29 13:32:11,763 - pid:1 [I] plugins.load:85 - Loaded plugin proxy.http.server.HttpWebServerPlugin
2023-04-29 13:32:11,763 - pid:1 [I] plugins.load:85 - Loaded plugin proxy.http.server.reverse.ReverseProxy
2023-04-29 13:32:11,764 - pid:1 [I] plugins.load:85 - Loaded plugin proxy.plugin.ReverseProxyPlugin
2023-04-29 13:32:11,764 - pid:1 [I] tcp.listen:80 - Listening on 0.0.0.0:80
2023-04-29 13:32:11,768 - pid:1 [D] pool._start:148 - Started acceptor#0 process 8
2023-04-29 13:32:11,771 - pid:1 [D] pool._start:148 - Started acceptor#1 process 9
2023-04-29 13:32:11,772 - pid:1 [I] pool.setup:105 - Started 2 acceptors in threadless (local) mode
2023-04-29 13:32:11,774 - pid:8 [D] selector_events.__init__:59 - Using selector: EpollSelector
2023-04-29 13:32:11,775 - pid:8 [D] threadless.run:412 - Working on 0 works
2023-04-29 13:32:11,777 - pid:9 [D] selector_events.__init__:59 - Using selector: EpollSelector
2023-04-29 13:32:11,778 - pid:9 [D] threadless.run:412 - Working on 0 works
2023-04-29 13:32:14,106 - pid:8 [D] acceptor.accept:115 - Accepting new work#15
2023-04-29 13:32:14,120 - pid:8 [D] tcp_server.__init__:119 - Work#15 accepted from x.x.x.x:57891
2023-04-29 13:32:14,121 - pid:8 [D] tcp_server.initialize:131 - Handling connection x.x.x.x:57891
2023-04-29 13:32:14,122 - pid:8 [D] threadless._update_work_events:196 - fd#15 registered for mask#1 by work#15
2023-04-29 13:32:14,122 - pid:8 [D] handler.handle_readables:216 - Client is read ready, receiving...
2023-04-29 13:32:14,123 - pid:8 [D] connection.recv:62 - received 417 bytes from client
2023-04-29 13:32:14,822 - pid:8 [D] threadless._update_work_events:196 - fd#16 registered for mask#3 by work#15
2023-04-29 13:32:14,823 - pid:8 [D] connection.flush:97 - flushed 417 bytes to server
2023-04-29 13:32:14,823 - pid:8 [D] threadless._update_work_events:166 - fd#16 modified for mask#1 by work#15
2023-04-29 13:32:17,114 - pid:8 [D] connection.recv:62 - received 845 bytes from server
2023-04-29 13:32:17,115 - pid:8 [D] threadless._update_work_events:166 - fd#15 modified for mask#3 by work#15
2023-04-29 13:32:17,116 - pid:8 [D] handler.handle_writables:188 - Client is write ready, flushing...
2023-04-29 13:32:17,116 - pid:8 [D] tcp_server.handle_writables:173 - Flushing buffer to client x.x.x.x:57891
2023-04-29 13:32:17,116 - pid:8 [D] connection.flush:97 - flushed 845 bytes to client
2023-04-29 13:32:17,117 - pid:8 [D] threadless._update_work_events:166 - fd#15 modified for mask#1 by work#15
2023-04-29 13:32:17,758 - pid:8 [D] handler.handle_readables:216 - Client is read ready, receiving...
2023-04-29 13:32:17,759 - pid:8 [D] connection.recv:62 - received 371 bytes from client
2023-04-29 13:32:18,458 - pid:8 [E] base_events.default_exception_handler:1729 - Task exception was never retrieved
future: <Task finished name='Task-1' coro=<Threadless._run_forever() done, defined at /usr/local/lib/python3.10/site-packages/proxy/core/work/threadless.py:376> exception=FileNotFoundError(2, 'No such file or directory')>
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/proxy/core/work/threadless.py", line 380, in _run_forever
    if await self._run_once():
  File "/usr/local/lib/python3.10/site-packages/proxy/core/work/threadless.py", line 341, in _run_once
    work_by_ids, new_work_available = await self._selected_events()
  File "/usr/local/lib/python3.10/site-packages/proxy/core/work/threadless.py", line 253, in _selected_events
    await self._update_selector()
  File "/usr/local/lib/python3.10/site-packages/proxy/core/work/threadless.py", line 232, in _update_selector
    await self._update_work_events(work_id)
  File "/usr/local/lib/python3.10/site-packages/proxy/core/work/threadless.py", line 161, in _update_work_events
    self.selector.modify(
  File "/usr/local/lib/python3.10/selectors.py", line 390, in modify
    self._selector.modify(key.fd, selector_events)
FileNotFoundError: [Errno 2] No such file or directory

Then I couldn’t access it anymore. I've tried pip install and got same result. I didn't find anything about it in the issue or discussion. I don't know if I misunderstood something or did something wrong.

Any help is appreciated.

[abhinavsingh]

In our integration tests, we do have end-to-end tests for reverse proxy plugin, but they run outside of docker container. I am just wondering iff this is specific to docker containers. Are you able to reproduce it when not using docker.

Can you please help verify the same w/o docker.

Thank you

[Unintendedz]

Hi there, thanks for getting back to me. I installed proxy.py using pip on a brand new VPS and tested the reverse proxy plugin, here are the results:

root@ubuntu-s-1vcpu-1gb-intel:~# pip install --upgrade proxy.py
Collecting proxy.py
  Downloading proxy.py-2.4.3-py3-none-any.whl (206 kB)
     ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 206.1/206.1 KB 3.4 MB/s eta 0:00:00
Installing collected packages: proxy.py
Successfully installed proxy.py-2.4.3
WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
root@ubuntu-s-1vcpu-1gb-intel:~# proxy
2023-05-01 23:36:26,685 - pid:3423 [I] plugins.load:85 - Loaded plugin proxy.http.proxy.HttpProxyPlugin
2023-05-01 23:36:26,685 - pid:3423 [I] tcp.listen:80 - Listening on 127.0.0.1:8899
2023-05-01 23:36:26,688 - pid:3423 [I] pool.setup:105 - Started 1 acceptors in threadless (local) mode
^C2023-05-01 23:36:28,432 - pid:3423 [I] proxy._handle_exit_signal:325 - Received signal 2
2023-05-01 23:36:28,432 - pid:3423 [I] pool.shutdown:125 - Shutting down 1 acceptors
root@ubuntu-s-1vcpu-1gb-intel:~# proxy --port 80 --hostname 0.0.0.0 --log-level d --enable-reverse-proxy --plugins proxy.plugin.ReverseProxyPlugin
2023-05-01 23:36:40,326 - pid:3426 [I] plugins.load:85 - Loaded plugin proxy.http.proxy.HttpProxyPlugin
2023-05-01 23:36:40,326 - pid:3426 [I] plugins.load:85 - Loaded plugin proxy.http.server.HttpWebServerPlugin
2023-05-01 23:36:40,326 - pid:3426 [I] plugins.load:85 - Loaded plugin proxy.http.server.reverse.ReverseProxy
2023-05-01 23:36:40,326 - pid:3426 [I] plugins.load:85 - Loaded plugin proxy.plugin.ReverseProxyPlugin
2023-05-01 23:36:40,327 - pid:3426 [I] tcp.listen:80 - Listening on 0.0.0.0:80
2023-05-01 23:36:40,329 - pid:3426 [D] pool._start:148 - Started acceptor#0 process 3427
2023-05-01 23:36:40,330 - pid:3426 [I] pool.setup:105 - Started 1 acceptors in threadless (local) mode
2023-05-01 23:36:40,334 - pid:3427 [D] selector_events.__init__:54 - Using selector: EpollSelector
2023-05-01 23:36:40,335 - pid:3427 [D] threadless.run:412 - Working on 0 works
2023-05-01 23:37:00,982 - pid:3427 [D] acceptor.accept:115 - Accepting new work#15
2023-05-01 23:37:01,002 - pid:3427 [D] tcp_server.__init__:119 - Work#15 accepted from x.x.x.x:46079
2023-05-01 23:37:01,003 - pid:3427 [D] tcp_server.initialize:131 - Handling connection x.x.x.x:46079
2023-05-01 23:37:01,003 - pid:3427 [D] threadless._update_work_events:196 - fd#15 registered for mask#1 by work#15
2023-05-01 23:37:01,004 - pid:3427 [D] handler.handle_readables:216 - Client is read ready, receiving...
2023-05-01 23:37:01,004 - pid:3427 [D] connection.recv:62 - received 393 bytes from client
2023-05-01 23:37:01,248 - pid:3427 [D] threadless._update_work_events:196 - fd#16 registered for mask#3 by work#15
2023-05-01 23:37:01,248 - pid:3427 [D] connection.flush:97 - flushed 393 bytes to server
2023-05-01 23:37:01,248 - pid:3427 [D] threadless._update_work_events:166 - fd#16 modified for mask#1 by work#15
2023-05-01 23:37:01,487 - pid:3427 [D] connection.recv:62 - received 815 bytes from server
2023-05-01 23:37:01,487 - pid:3427 [D] threadless._update_work_events:166 - fd#15 modified for mask#3 by work#15
2023-05-01 23:37:01,487 - pid:3427 [D] handler.handle_writables:188 - Client is write ready, flushing...
2023-05-01 23:37:01,488 - pid:3427 [D] tcp_server.handle_writables:173 - Flushing buffer to client x.x.x.x:46079
2023-05-01 23:37:01,488 - pid:3427 [D] connection.flush:97 - flushed 815 bytes to client
2023-05-01 23:37:01,488 - pid:3427 [D] threadless._update_work_events:166 - fd#15 modified for mask#1 by work#15
2023-05-01 23:37:02,179 - pid:3427 [D] handler.handle_readables:216 - Client is read ready, receiving...
2023-05-01 23:37:02,180 - pid:3427 [D] connection.recv:62 - received 375 bytes from client
2023-05-01 23:37:02,408 - pid:3427 [E] base_events.default_exception_handler:1744 - Task exception was never retrieved
future: <Task finished name='Task-1' coro=<Threadless._run_forever() done, defined at /usr/local/lib/python3.10/dist-packages/proxy/core/work/threadless.py:376> exception=FileNotFoundError(2, 'No such file or directory')>
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/dist-packages/proxy/core/work/threadless.py", line 380, in _run_forever
    if await self._run_once():
  File "/usr/local/lib/python3.10/dist-packages/proxy/core/work/threadless.py", line 341, in _run_once
    work_by_ids, new_work_available = await self._selected_events()
  File "/usr/local/lib/python3.10/dist-packages/proxy/core/work/threadless.py", line 253, in _selected_events
    await self._update_selector()
  File "/usr/local/lib/python3.10/dist-packages/proxy/core/work/threadless.py", line 232, in _update_selector
    await self._update_work_events(work_id)
  File "/usr/local/lib/python3.10/dist-packages/proxy/core/work/threadless.py", line 161, in _update_work_events
    self.selector.modify(
  File "/usr/lib/python3.10/selectors.py", line 390, in modify
    self._selector.modify(key.fd, selector_events)
FileNotFoundError: [Errno 2] No such file or directory
2023-05-01 23:37:10,069 - pid:3427 [D] acceptor.accept:115 - Accepting new work#5

[abhinavsingh]

Thank you for verifying. I am suspecting this is Ubuntu (Linux) specific somehow. I did try reverse proxy example from our README.md on my MacBook and I wasn't able to reproduce the same. I'll give it a try in the coming week on my Linux system and try to reproduce.

TL;DR -- From the looks of it, core is trying to process a closed socket.

Quick question:
Does this error prevent from completing the reverse proxy response.

Thank you

[Unintendedz]

Does this error prevent from completing the reverse proxy response.

Yes, the error occurs after the first response is completed, and no response can be obtained when accessed again.
There is only this last record in the log: 2023-05-01 23:37:10,069 - pid:3427 [D] acceptor.accept:115 - Accepting new work#5.

I am suspecting this is Ubuntu (Linux) specific somehow.

Based on my test results on CentOS, it appears that the issue may not be limited to Ubuntu. Here are the test logs from CentOS, hope this information will be helpful.

[root@centos-s-1vcpu-2gb-intel-nyc1-01 ~]# pip install --upgrade proxy.py
Collecting proxy.py
  Downloading proxy.py-2.4.3-py3-none-any.whl (206 kB)
     |████████████████████████████████| 206 kB 2.9 MB/s
Installing collected packages: proxy.py
Successfully installed proxy.py-2.4.3
WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
[root@centos-s-1vcpu-2gb-intel-nyc1-01 ~]# proxy --port 80 --hostname 0.0.0.0 --log-level d --enable-reverse-proxy --plugins proxy.plugin.ReverseProxyPlugin
2023-05-03 02:06:27,695 - pid:14491 [I] plugins.load:85 - Loaded plugin proxy.http.proxy.HttpProxyPlugin
2023-05-03 02:06:27,696 - pid:14491 [I] plugins.load:85 - Loaded plugin proxy.http.server.HttpWebServerPlugin
2023-05-03 02:06:27,696 - pid:14491 [I] plugins.load:85 - Loaded plugin proxy.http.server.reverse.ReverseProxy
2023-05-03 02:06:27,697 - pid:14491 [I] plugins.load:85 - Loaded plugin proxy.plugin.ReverseProxyPlugin
2023-05-03 02:06:27,698 - pid:14491 [I] tcp.listen:80 - Listening on 0.0.0.0:80
2023-05-03 02:06:27,701 - pid:14491 [D] pool._start:148 - Started acceptor#0 process 14492
2023-05-03 02:06:27,702 - pid:14491 [I] pool.setup:105 - Started 1 acceptors in threadless (local) mode
2023-05-03 02:06:27,708 - pid:14492 [D] selector_events.__init__:59 - Using selector: EpollSelector
2023-05-03 02:06:27,709 - pid:14492 [D] threadless.run:412 - Working on 0 works
2023-05-03 02:06:45,946 - pid:14492 [D] acceptor.accept:115 - Accepting new work#15
2023-05-03 02:06:45,965 - pid:14492 [D] tcp_server.__init__:119 - Work#15 accepted from x.x.x.x:27909
2023-05-03 02:06:45,965 - pid:14492 [D] tcp_server.initialize:131 - Handling connection x.x.x.x:27909
2023-05-03 02:06:45,965 - pid:14492 [D] threadless._update_work_events:196 - fd#15 registered for mask#1 by work#15
2023-05-03 02:06:45,966 - pid:14492 [D] handler.handle_readables:216 - Client is read ready, receiving...
2023-05-03 02:06:45,966 - pid:14492 [D] connection.recv:62 - received 391 bytes from client
2023-05-03 02:06:45,980 - pid:14492 [D] threadless._update_work_events:196 - fd#16 registered for mask#3 by work#15
2023-05-03 02:06:45,980 - pid:14492 [D] connection.flush:97 - flushed 391 bytes to server
2023-05-03 02:06:45,981 - pid:14492 [D] threadless._update_work_events:166 - fd#16 modified for mask#1 by work#15
2023-05-03 02:06:46,002 - pid:14492 [D] connection.recv:62 - received 809 bytes from server
2023-05-03 02:06:46,002 - pid:14492 [D] threadless._update_work_events:166 - fd#15 modified for mask#3 by work#15
2023-05-03 02:06:46,003 - pid:14492 [D] handler.handle_writables:188 - Client is write ready, flushing...
2023-05-03 02:06:46,003 - pid:14492 [D] tcp_server.handle_writables:173 - Flushing buffer to client x.x.x.x:27909
2023-05-03 02:06:46,003 - pid:14492 [D] connection.flush:97 - flushed 809 bytes to client
2023-05-03 02:06:46,003 - pid:14492 [D] threadless._update_work_events:166 - fd#15 modified for mask#1 by work#15
2023-05-03 02:06:51,125 - pid:14492 [D] handler.handle_readables:216 - Client is read ready, receiving...
2023-05-03 02:06:51,126 - pid:14492 [D] tcp_server.handle_readables:203 - Connection closed by client x.x.x.x:27909
2023-05-03 02:06:51,126 - pid:14492 [D] threadless._cleanup:303 - fd#15 unregistered by work#15
2023-05-03 02:06:51,126 - pid:14492 [D] threadless._cleanup:303 - fd#16 unregistered by work#15
2023-05-03 02:06:51,126 - pid:14492 [D] reverse.on_client_connection_close:101 - Closing upstream server connection
2023-05-03 02:06:51,126 - pid:14492 [I] reverse.on_access_log:109 - x.x.x.x:27909 - GET /get -> http://httpbin.org/get - 5159.59ms
2023-05-03 02:06:51,127 - pid:14492 [D] handler.shutdown:87 - Closing client connection x.x.x.x:27909 has buffer False
2023-05-03 02:06:51,127 - pid:14492 [D] handler.shutdown:97 - Client connection shutdown successful
2023-05-03 02:06:51,127 - pid:14492 [D] handler.shutdown:111 - Client connection closed
2023-05-03 02:06:53,852 - pid:14492 [D] acceptor.accept:115 - Accepting new work#15
2023-05-03 02:06:53,858 - pid:14492 [D] tcp_server.__init__:119 - Work#15 accepted from x.x.x.x:58363
2023-05-03 02:06:53,859 - pid:14492 [D] tcp_server.initialize:131 - Handling connection x.x.x.x:58363
2023-05-03 02:06:53,859 - pid:14492 [D] threadless._update_work_events:196 - fd#15 registered for mask#1 by work#15
2023-05-03 02:06:53,859 - pid:14492 [D] handler.handle_readables:216 - Client is read ready, receiving...
2023-05-03 02:06:53,860 - pid:14492 [D] connection.recv:62 - received 417 bytes from client
2023-05-03 02:06:53,868 - pid:14492 [D] threadless._update_work_events:196 - fd#16 registered for mask#3 by work#15
2023-05-03 02:06:53,869 - pid:14492 [D] connection.flush:97 - flushed 417 bytes to server
2023-05-03 02:06:53,869 - pid:14492 [D] threadless._update_work_events:166 - fd#16 modified for mask#1 by work#15
2023-05-03 02:06:55,077 - pid:14492 [D] connection.recv:62 - received 844 bytes from server
2023-05-03 02:06:55,078 - pid:14492 [D] threadless._update_work_events:166 - fd#15 modified for mask#3 by work#15
2023-05-03 02:06:55,078 - pid:14492 [D] handler.handle_writables:188 - Client is write ready, flushing...
2023-05-03 02:06:55,078 - pid:14492 [D] tcp_server.handle_writables:173 - Flushing buffer to client x.x.x.x:58363
2023-05-03 02:06:55,079 - pid:14492 [D] connection.flush:97 - flushed 844 bytes to client
2023-05-03 02:06:55,079 - pid:14492 [D] threadless._update_work_events:166 - fd#15 modified for mask#1 by work#15
2023-05-03 02:06:55,979 - pid:14492 [D] handler.handle_readables:216 - Client is read ready, receiving...
2023-05-03 02:06:55,979 - pid:14492 [D] connection.recv:62 - received 371 bytes from client
2023-05-03 02:06:55,990 - pid:14492 [E] base_events.default_exception_handler:1738 - Task exception was never retrieved
future: <Task finished name='Task-1' coro=<Threadless._run_forever() done, defined at /usr/local/lib/python3.9/site-packages/proxy/core/work/threadless.py:376> exception=FileNotFoundError(2, 'No such file or directory')>
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/proxy/core/work/threadless.py", line 380, in _run_forever
    if await self._run_once():
  File "/usr/local/lib/python3.9/site-packages/proxy/core/work/threadless.py", line 341, in _run_once
    work_by_ids, new_work_available = await self._selected_events()
  File "/usr/local/lib/python3.9/site-packages/proxy/core/work/threadless.py", line 253, in _selected_events
    await self._update_selector()
  File "/usr/local/lib/python3.9/site-packages/proxy/core/work/threadless.py", line 232, in _update_selector
    await self._update_work_events(work_id)
  File "/usr/local/lib/python3.9/site-packages/proxy/core/work/threadless.py", line 161, in _update_work_events
    self.selector.modify(
  File "/usr/lib64/python3.9/selectors.py", line 390, in modify
    self._selector.modify(key.fd, selector_events)
FileNotFoundError: [Errno 2] No such file or directory
2023-05-03 02:07:05,336 - pid:14492 [D] acceptor.accept:115 - Accepting new work#5

[abhinavsingh]

Thanks a ton for cross verifying it, I will take a look into it in coming days.