TLS Intercept conditionally

[abhinavsingh]

Fixes

• How to disable TLS interception conditionally? #1432

[abhinavsingh]

@kuefmz @JJ-Author Can you give this PR a try? This PR fixes logic where conditionally TLS interception wasn't working as expected. Please let me know if something is still amiss. Thank you for reporting this.

[codecov]

Codecov Report

Attention: Patch coverage is 77.27273% with 5 lines in your changes missing coverage. Please review.

Project coverage is 84.71%. Comparing base (a51ddaa) to head (9c97cca).
Report is 15 commits behind head on develop.

Files with missing lines	Patch %	Lines
proxy/plugin/tls_intercept_conditionally.py	62.50%	3 Missing ⚠️
proxy/http/proxy/server.py	84.61%	1 Missing and 1 partial ⚠️

Additional details and impacted files

@@             Coverage Diff             @@
##           develop    #1476      +/-   ##
===========================================
- Coverage    85.55%   84.71%   -0.85%     
===========================================
  Files          176      183       +7     
  Lines         7659     8343     +684     
  Branches       815     1273     +458     
===========================================
+ Hits          6553     7068     +515     
- Misses         947     1071     +124     
- Partials       159      204      +45     

Flag	Coverage Δ
GHA	84.56% <77.27%> (-0.83%)	⬇️
Linux	84.20% <72.72%> (?)
Python 3.10	85.24% <62.50%> (-0.03%)	⬇️
Python 3.11	84.45% <77.27%> (?)
Python 3.12	84.45% <77.27%> (?)
Python 3.6	85.20% <62.50%> (-0.03%)	⬇️
Python 3.7	85.20% <62.50%> (-0.03%)	⬇️
Python 3.8	85.24% <62.50%> (-0.03%)	⬇️
Python 3.9	85.30% <62.50%> (-0.03%)	⬇️
Windows	77.98% <77.27%> (-0.23%)	⬇️
macOS	84.56% <77.27%> (-0.83%)	⬇️
pytest	84.56% <77.27%> (-0.83%)	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[abhinavsingh]

@webknjaz I am wondering if you have encountered following error in other projects:

Running Sphinx v4.3.2
loading translations [en]... done
Initializing Spelling Checker 8.0.0
making output directory... done
Ignoring wiki words
Ignoring acronyms
Adding package names from PyPI to local dictionary…

Exception occurred:
  File "/opt/hostedtoolcache/Python/3.10.15/x64/lib/python3.10/xmlrpc/client.py", line 668, in close
    raise Fault(**self._stack[0])
xmlrpc.client.Fault: <Fault -32500: 'RuntimeError: PyPI no longer supports the XMLRPC list_packages method. Use JSON or Simple API instead. See https://github.com/pypi/warehouse/issues/16642 and https://warehouse.pypa.io/api-reference/xml-rpc.html#deprecated-methods for more information.'>
The full traceback has been saved in /tmp/sphinx-err-b2ijmmb5.log, if you want to report the issue to the developers.
Please also report this if it was a user error, so that a better error message can be provided next time.
A bug report can be filed in the tracker at <https://github.com/sphinx-doc/sphinx/issues>. Thanks!
ERROR: InvocationError for command /home/runner/work/proxy.py/proxy.py/.tox/spellcheck-docs/bin/python -m sphinx -j auto -a -n -W --keep-going -b spelling --color -d /home/runner/work/proxy.py/proxy.py/.tox/docs_doctree . /home/runner/work/proxy.py/proxy.py/.tox/docs_out (exited with code 2)
ERROR: invocation failed (exit code 1)
✖ FAIL spellcheck-docs in 10.504 seconds
___________________________________ summary ____________________________________
ERROR:   spellcheck-docs: parallel child exit code 1

Error: Process completed with exit code 1.

I bumped sphinxcontrib-spelling to version 8.0.0 but looks like problem might be rooted somewhere else. Wondering whether Sphinx itself should be upgraded here? If yes, IIRC, this might not be an easy peasy task. Looking for some insights how to proceed w/o disabling spell check.

[webknjaz]

Yes, I've filed an upstream issue. But for now, just disable this feature.

[abhinavsingh]

@webknjaz Thank you 🙏

[JJ-Author]

great. thank you very much. that seems to solve the issue.

[JJ-Author]

i think there is still a bug in the interception logic.
I found that it is not handling proxied websocket request correctly - so they wont work.
those are sent via connect but without tls (in case it is ws and not wss - wss proxying seems to work)
it`s a similiar behaviour from the outside compared to the once broken interception=false issue
the connection is somehow stalled for 60 seconds and then closed by proxypy with an error on the log.

suspicious/wrong seems that "plain" CONNECT requests trigger the do_intercept event because I cant tls-intercept unencrypted calls, right ;-) ?

2024-09-26 13:13:53,457 - pid:226536 [D] acceptor.accept:115 - Accepting new work#87                                                                                [320/1847]
2024-09-26 13:13:53,476 - pid:226536 [D] tcp_server.__init__:119 - Work#87 accepted from 127.0.0.1:44065                                                                      
2024-09-26 13:13:53,476 - pid:226536 [D] tcp_server.initialize:131 - Handling connection 127.0.0.1:44065                                                                      
2024-09-26 13:13:53,477 - pid:226536 [D] threadless._update_work_events:197 - fd#87 registered for mask#1 by work#87                                                          
2024-09-26 13:13:53,477 - pid:226536 [D] handler.handle_readables:222 - Client is read ready, receiving...                                                                    
2024-09-26 13:13:53,477 - pid:226536 [D] connection.recv:62 - received 93 bytes from client                                                                                   
2024-09-26 13:13:53,477 - pid:226536 [D] server.connect_upstream:578 - Connecting to upstream echo.websocket.events:80                                                        
2024-09-26 13:13:53,642 - pid:226536 [D] server.connect_upstream:613 - Connected to upstream echo.websocket.events:80                                                         
Do intercept triggered: {'state': 6, 'type': 1, 'protocol': None, 'host': b'echo.websocket.events', 'port': 80, 'path': None, 'method': b'CONNECT', 'code': None, 'reason': No
ne, 'version': b'HTTP/1.1', 'total_size': 93, 'buffer': None, 'headers': {b'host': (b'Host', b'echo.websocket.events'), b'connection': (b'Connection', b'close')}, 'body': Non
e, 'chunk': None, '_url': <proxy.http.url.Url object at 0x7fe8e3c9a2f0>, '_is_chunked_encoded': False, '_content_expected': False, '_is_https_tunnel': True}                  
                                                                                                                                                                              
2024-09-26 13:14:07,365 - pid:226535 [D] acceptor.accept:115 - Accepting new work#83                                                                                          
2024-09-26 13:14:07,375 - pid:226536 [D] acceptor.accept:115 - Accepting new work#89                                                                                          
2024-09-26 13:14:07,390 - pid:226535 [D] tcp_server.__init__:119 - Work#83 accepted from 80.93.184.220:36916                                                                  
2024-09-26 13:14:07,390 - pid:226535 [D] tcp_server.initialize:131 - Handling connection 80.93.184.220:36916                                                                  
2024-09-26 13:14:07,390 - pid:226535 [D] threadless._update_work_events:197 - fd#83 registered for mask#1 by work#83                                                          
2024-09-26 13:14:07,391 - pid:226535 [D] handler.handle_readables:222 - Client is read ready, receiving...                                                                    
2024-09-26 13:14:07,391 - pid:226535 [D] connection.recv:62 - received 3 bytes from client                                                                                    
2024-09-26 13:14:18,289 - pid:226535 [D] threadless._cleanup:311 - fd#83 unregistered by work#83                                                                              
2024-09-26 13:14:18,289 - pid:226535 [D] handler.shutdown:89 - Closing client connection 80.93.184.220:36916 has buffer False                                                 
2024-09-26 13:14:18,289 - pid:226535 [D] handler.shutdown:99 - Client connection shutdown successful                                                                          
2024-09-26 13:14:18,289 - pid:226535 [D] handler.shutdown:113 - Client connection closed                                                                                      
2024-09-26 13:14:53,745 - pid:226536 [E] server.wrap_server:802 - SSLError when wrapping client for upstream: echo.websocket.events                                           
Traceback (most recent call last):                                                                                                                                            
  File "/root/.cache/pypoetry/virtualenvs/proxy-test-f6SwClI5-py3.10/lib/python3.10/site-packages/proxy/http/proxy/server.py", line 776, in wrap_server                       
    self.upstream.wrap(                                                                                                                                                       
  File "/root/.cache/pypoetry/virtualenvs/proxy-test-f6SwClI5-py3.10/lib/python3.10/site-packages/proxy/core/connection/server.py", line 63, in wrap                          
    self._conn = ctx.wrap_socket(                                                                                                                                             
  File "/root/.pyenv/versions/3.10.14/lib/python3.10/ssl.py", line 513, in wrap_socket                                                                                        
    return self.sslsocket_class._create(                                                                                                                                      
  File "/root/.pyenv/versions/3.10.14/lib/python3.10/ssl.py", line 1104, in _create                                                                                           
    self.do_handshake()                                                                                                                                                       
  File "/root/.pyenv/versions/3.10.14/lib/python3.10/ssl.py", line 1375, in do_handshake                                                                                      
    self._sslobj.do_handshake()                                                                                                                                               
ssl.SSLEOFError: EOF occurred in violation of protocol (_ssl.c:1007)                                                                                                          
2024-09-26 13:14:53,747 - pid:226536 [D] tcp_server.handle_readables:212 - Implementation signaled shutdown for client 127.0.0.1:44065                                        
2024-09-26 13:14:53,747 - pid:226536 [D] tcp_server.handle_readables:218 - Client 127.0.0.1:44065 has pending buffer, will be flushed before shutting down
2024-09-26 13:14:53,748 - pid:226536 [D] threadless._update_work_events:166 - fd#87 modified for mask#2 by work#87
2024-09-26 13:14:53,748 - pid:226536 [D] tcp_server.__init__:119 - Work#89 accepted from 80.93.184.220:36918
2024-09-26 13:14:53,748 - pid:226536 [D] tcp_server.initialize:131 - Handling connection 80.93.184.220:36918
2024-09-26 13:14:53,748 - pid:226536 [D] handler.handle_writables:193 - Client is write ready, flushing...
2024-09-26 13:14:53,748 - pid:226536 [D] tcp_server.handle_writables:173 - Flushing buffer to client 127.0.0.1:44065
2024-09-26 13:14:53,748 - pid:226536 [D] connection.flush:101 - flushed 39 bytes to client
2024-09-26 13:14:53,748 - pid:226536 [D] threadless._cleanup:311 - fd#87 unregistered by work#87
2024-09-26 13:14:53,748 - pid:226536 [I] server.access_log:393 - 127.0.0.1:44065 - CONNECT echo.websocket.events:80 - 0 bytes - 60271.17ms
2024-09-26 13:14:53,749 - pid:226536 [D] server.on_client_connection_close:384 - Closed server connection, has buffer False

I used the following wscat command to test
docker run -it --rm node:alpine sh -c "npm install -g [email protected] && wscat -c ws://echo.websocket.events --no-check --proxy http://172.17.0.1:8899"

and also had a look when putting socat in between

    (proxy-test-py3.10) (base) root@APP-DBpedia /srv/archivo/time-machine/https-interception-proxypy$ socat -v TCP-LISTEN:8081,reuseaddr,fork TCP:localhost:8899       130 ↵ 
 ✹ ✭main                                                                                                                                                                      
> 2024/09/26 13:46:02.159672  length=93 from=0 to=92                                                                                                                          
CONNECT echo.websocket.events:80 HTTP/1.1\r                                            
Host: echo.websocket.events\r                                                          
Connection: close\r                                                                    
\r                                                                                     
< 2024/09/26 13:47:02.450437  length=39 from=0 to=38                                                                                                                          
HTTP/1.1 200 Connection established\r                                                  
\r                                                                                     
> 2024/09/26 13:47:02.454326  length=230 from=93 to=322                                                                                                                       
GET / HTTP/1.1\r                                                                       
Sec-WebSocket-Version: 13\r                                                            
Sec-WebSocket-Key: qfRVo9lecGCkVkjeq2BJzw==\r                                                                                                                                 
Connection: Upgrade\r                                                                  
Upgrade: websocket\r                                                                   
Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits\r                                                                                                        
Host: echo.websocket.events\r                                                          
\r                                                                                     
> 2024/09/26 13:51:17.670946  length=89 from=0 to=88                                                                                                                          
CONNECT google.com:443 HTTP/1.1\r                                                      
Host: google.com:443\r                                                                 
User-Agent: Go-http-client/1.1\r                                                       
\r                                                                                     
< 2024/09/26 13:51:17.700995  length=39 from=0 to=38                                                                                                                          
HTTP/1.1 200 Connection established\r                                                  
\r                                                                                     
> 2024/09/26 13:51:17.732569  length=262 from=89 to=350                                                                                                                       
............c....."...l.^.Vq(..*P.Z..C...>h <...1y.N..sVat7\\..F.Qp.6.......T.&.+./.,.0.....    ...
......./.5...                                                                          
...............\r..                                                                    
google.com..........                                                                   
.                                                                                      
.\b.........\v.....\r....\b...\b\a\b.\b.............................+........3.&.$... ...(...{ro...':B.ao[-.....%...}j< 2024/09/26 13:51:17.734828  length=1359 from=39 to=139
7

I dont have a use case at the moment where I need to rely on unsecured websockets, so Im just reporting it
for the sake of the reliability of the proxypy project.
but since you just dived into the logic, maybe you have ambition s to fix it as long as you remember the details^^

[webknjaz]

@abhinavsingh

This is the upstream issue: sphinx-contrib/spelling#227.
I didn't mean disabling the entire check, just flipping the PyPI lookup setting: ansible/awx-plugins@842fb8d.

[abhinavsingh]

i think there is still a bug in the interception logic. I found that it is not handling proxied websocket request correctly - so they wont work. those are sent via connect but without tls (in case it is ws and not wss - wss proxying seems to work) it`s a similiar behaviour from the outside compared to the once broken interception=false issue the connection is somehow stalled for 60 seconds and then closed by proxypy with an error on the log.

suspicious/wrong seems that "plain" CONNECT requests trigger the do_intercept event because I cant tls-intercept unencrypted calls, right ;-) ?

2024-09-26 13:13:53,457 - pid:226536 [D] acceptor.accept:115 - Accepting new work#87 [320/1847]
2024-09-26 13:13:53,476 - pid:226536 [D] tcp_server.init:119 - Work#87 accepted from 127.0.0.1:44065
2024-09-26 13:13:53,476 - pid:226536 [D] tcp_server.initialize:131 - Handling connection 127.0.0.1:44065
2024-09-26 13:13:53,477 - pid:226536 [D] threadless._update_work_events:197 - fd#87 registered for mask#1 by work#87
2024-09-26 13:13:53,477 - pid:226536 [D] handler.handle_readables:222 - Client is read ready, receiving...
2024-09-26 13:13:53,477 - pid:226536 [D] connection.recv:62 - received 93 bytes from client
2024-09-26 13:13:53,477 - pid:226536 [D] server.connect_upstream:578 - Connecting to upstream echo.websocket.events:80
2024-09-26 13:13:53,642 - pid:226536 [D] server.connect_upstream:613 - Connected to upstream echo.websocket.events:80
Do intercept triggered: {'state': 6, 'type': 1, 'protocol': None, 'host': b'echo.websocket.events', 'port': 80, 'path': None, 'method': b'CONNECT', 'code': None, 'reason': No
ne, 'version': b'HTTP/1.1', 'total_size': 93, 'buffer': None, 'headers': {b'host': (b'Host', b'echo.websocket.events'), b'connection': (b'Connection', b'close')}, 'body': Non
e, 'chunk': None, '_url': <proxy.http.url.Url object at 0x7fe8e3c9a2f0>, '_is_chunked_encoded': False, '_content_expected': False, '_is_https_tunnel': True}

2024-09-26 13:14:07,365 - pid:226535 [D] acceptor.accept:115 - Accepting new work#83
2024-09-26 13:14:07,375 - pid:226536 [D] acceptor.accept:115 - Accepting new work#89
2024-09-26 13:14:07,390 - pid:226535 [D] tcp_server.init:119 - Work#83 accepted from 80.93.184.220:36916
2024-09-26 13:14:07,390 - pid:226535 [D] tcp_server.initialize:131 - Handling connection 80.93.184.220:36916
2024-09-26 13:14:07,390 - pid:226535 [D] threadless._update_work_events:197 - fd#83 registered for mask#1 by work#83
2024-09-26 13:14:07,391 - pid:226535 [D] handler.handle_readables:222 - Client is read ready, receiving...
2024-09-26 13:14:07,391 - pid:226535 [D] connection.recv:62 - received 3 bytes from client
2024-09-26 13:14:18,289 - pid:226535 [D] threadless._cleanup:311 - fd#83 unregistered by work#83
2024-09-26 13:14:18,289 - pid:226535 [D] handler.shutdown:89 - Closing client connection 80.93.184.220:36916 has buffer False
2024-09-26 13:14:18,289 - pid:226535 [D] handler.shutdown:99 - Client connection shutdown successful
2024-09-26 13:14:18,289 - pid:226535 [D] handler.shutdown:113 - Client connection closed
2024-09-26 13:14:53,745 - pid:226536 [E] server.wrap_server:802 - SSLError when wrapping client for upstream: echo.websocket.events
Traceback (most recent call last):
File "/root/.cache/pypoetry/virtualenvs/proxy-test-f6SwClI5-py3.10/lib/python3.10/site-packages/proxy/http/proxy/server.py", line 776, in wrap_server
self.upstream.wrap(
File "/root/.cache/pypoetry/virtualenvs/proxy-test-f6SwClI5-py3.10/lib/python3.10/site-packages/proxy/core/connection/server.py", line 63, in wrap
self._conn = ctx.wrap_socket(
File "/root/.pyenv/versions/3.10.14/lib/python3.10/ssl.py", line 513, in wrap_socket
return self.sslsocket_class._create(
File "/root/.pyenv/versions/3.10.14/lib/python3.10/ssl.py", line 1104, in _create
self.do_handshake()
File "/root/.pyenv/versions/3.10.14/lib/python3.10/ssl.py", line 1375, in do_handshake
self._sslobj.do_handshake()
ssl.SSLEOFError: EOF occurred in violation of protocol (_ssl.c:1007)
2024-09-26 13:14:53,747 - pid:226536 [D] tcp_server.handle_readables:212 - Implementation signaled shutdown for client 127.0.0.1:44065
2024-09-26 13:14:53,747 - pid:226536 [D] tcp_server.handle_readables:218 - Client 127.0.0.1:44065 has pending buffer, will be flushed before shutting down
2024-09-26 13:14:53,748 - pid:226536 [D] threadless._update_work_events:166 - fd#87 modified for mask#2 by work#87
2024-09-26 13:14:53,748 - pid:226536 [D] tcp_server.init:119 - Work#89 accepted from 80.93.184.220:36918
2024-09-26 13:14:53,748 - pid:226536 [D] tcp_server.initialize:131 - Handling connection 80.93.184.220:36918
2024-09-26 13:14:53,748 - pid:226536 [D] handler.handle_writables:193 - Client is write ready, flushing...
2024-09-26 13:14:53,748 - pid:226536 [D] tcp_server.handle_writables:173 - Flushing buffer to client 127.0.0.1:44065
2024-09-26 13:14:53,748 - pid:226536 [D] connection.flush:101 - flushed 39 bytes to client
2024-09-26 13:14:53,748 - pid:226536 [D] threadless._cleanup:311 - fd#87 unregistered by work#87
2024-09-26 13:14:53,748 - pid:226536 [I] server.access_log:393 - 127.0.0.1:44065 - CONNECT echo.websocket.events:80 - 0 bytes - 60271.17ms
2024-09-26 13:14:53,749 - pid:226536 [D] server.on_client_connection_close:384 - Closed server connection, has buffer False
I used the following wscat command to test docker run -it --rm node:alpine sh -c "npm install -g [email protected] && wscat -c ws://echo.websocket.events --no-check --proxy http://172.17.0.1:8899"

and also had a look when putting socat in between

(proxy-test-py3.10) (base) root@APP-DBpedia /srv/archivo/time-machine/https-interception-proxypy$ socat -v TCP-LISTEN:8081,reuseaddr,fork TCP:localhost:8899       130 ↵ 

✹ ✭main

2024/09/26 13:46:02.159672 length=93 from=0 to=92
CONNECT echo.websocket.events:80 HTTP/1.1\r
Host: echo.websocket.events\r
Connection: close\r
\r
< 2024/09/26 13:47:02.450437 length=39 from=0 to=38
HTTP/1.1 200 Connection established\r
\r
2024/09/26 13:47:02.454326 length=230 from=93 to=322
GET / HTTP/1.1\r
Sec-WebSocket-Version: 13\r
Sec-WebSocket-Key: qfRVo9lecGCkVkjeq2BJzw==\r
Connection: Upgrade\r
Upgrade: websocket\r
Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits\r
Host: echo.websocket.events\r
\r
2024/09/26 13:51:17.670946 length=89 from=0 to=88
CONNECT google.com:443 HTTP/1.1\r
Host: google.com:443\r
User-Agent: Go-http-client/1.1\r
\r
< 2024/09/26 13:51:17.700995 length=39 from=0 to=38
HTTP/1.1 200 Connection established\r
\r
2024/09/26 13:51:17.732569 length=262 from=89 to=350
............c....."...l.^.Vq(..*P.Z..C...>h <...1y.N..sVat7\..F.Qp.6.......T.&.+./.,.0..... ...
......./.5...
...............\r..
google.com..........
.
.\b.........\v.....\r....\b...\b\a\b.\b.............................+........3.&.$... ...(...{ro...':B.ao[-.....%...}j< 2024/09/26 13:51:17.734828 length=1359 from=39 to=139
7
I dont have a use case at the moment where I need to rely on unsecured websockets, so Im just reporting it for the sake of the reliability of the proxypy project. but since you just dived into the logic, maybe you have ambition s to fix it as long as you remember the details^^

Thank you @JJ-Author for reporting this. Indeed, every bug needs to be resolved someday 🗡️ I will dig into your analysis further and see what can be done about it.