Broken pipe in the tunnel

[Future998]

Broken pipe in the tunnel

[Future998]

I sent everything that was in the file out.txt . After that, an error occurs, apparently.
When enabling the debug on the client:

DEBUG 2023-06-13 11:25:13,273 Platform info:
DEBUG 2023-06-13 11:25:13,273   Platform: Linux-5.15.78-std-def-alt1-x86_64-with-glibc2.35
DEBUG 2023-06-13 11:25:13,274   Node: alexander
DEBUG 2023-06-13 11:25:13,274   System: Linux
DEBUG 2023-06-13 11:25:13,274   Release: 5.15.78-std-def-alt1
DEBUG 2023-06-13 11:25:13,274   Version: #1 SMP Thu Nov 10 21:13:39 UTC 2022
DEBUG 2023-06-13 11:25:13,274   Machine: x86_64
DEBUG 2023-06-13 11:25:13,274   Processor: 
DEBUG 2023-06-13 11:25:13,276   Architecture: ('64bit', 'ELF')
DEBUG 2023-06-13 11:25:13,276   Python version: 3.10.8
DEBUG 2023-06-13 11:25:13,276   Python implementation: CPython
DEBUG 2023-06-13 11:25:13,276   Python compiler: GCC 12.1.1 20220518 (ALT Sisyphus 12.1.1-alt2)
DEBUG 2023-06-13 11:25:13,276   Python build: ('main', 'Dec 17 2022 11:34:59')
DEBUG 2023-06-13 11:25:13,276 Log level set to DEBUG
DEBUG 2023-06-13 11:25:13,276 Environment variables:
DEBUG 2023-06-13 11:25:13,276   LD_LIBRARY_PATH=/usr/lib64/chromium
DEBUG 2023-06-13 11:25:13,276   LIBVA_DRIVERS_PATH=/usr/lib64/dri
DEBUG 2023-06-13 11:25:13,276   XDG_MENU_PREFIX=gnome-
DEBUG 2023-06-13 11:25:13,276   LANG=ru_RU.UTF-8
DEBUG 2023-06-13 11:25:13,276   GDM_LANG=ru_RU.UTF-8
DEBUG 2023-06-13 11:25:13,276   LESS=-MM
DEBUG 2023-06-13 11:25:13,277   MANAGERPID=4434
DEBUG 2023-06-13 11:25:13,277   SYSTEMD_EXEC_PID=4618
DEBUG 2023-06-13 11:25:13,277   DISPLAY=:0
DEBUG 2023-06-13 11:25:13,277   HOSTNAME=alexander
DEBUG 2023-06-13 11:25:13,277   INVOCATION_ID=e2f746d7eac3494bb484522c4ffeac4f
DEBUG 2023-06-13 11:25:13,277   GPG_TTY=не телетайп
DEBUG 2023-06-13 11:25:13,277   USERNAME=alexander
DEBUG 2023-06-13 11:25:13,277   JAVA_HOME=/usr/lib/jvm/jre
DEBUG 2023-06-13 11:25:13,277   NO_AT_BRIDGE=1
DEBUG 2023-06-13 11:25:13,277   GIO_LAUNCHED_DESKTOP_FILE_PID=13884
DEBUG 2023-06-13 11:25:13,277   SSH_AUTH_SOCK=/run/user/500/keyring/ssh
DEBUG 2023-06-13 11:25:13,277   USER=alexander
DEBUG 2023-06-13 11:25:13,277   DESKTOP_SESSION=gnome
DEBUG 2023-06-13 11:25:13,277   MM_NOTTTY=1
DEBUG 2023-06-13 11:25:13,277   WAYLAND_DISPLAY=wayland-0
DEBUG 2023-06-13 11:25:13,277   XDG_ACTIVATION_TOKEN=gnome-shell/Веб-браузер Chromium/4618-1-alexander_TIME1679766
DEBUG 2023-06-13 11:25:13,277   PWD=/home/alexander
DEBUG 2023-06-13 11:25:13,277   SSH_ASKPASS=/usr/lib/openssh/ssh-askpass
DEBUG 2023-06-13 11:25:13,277   HOME=/home/alexander
DEBUG 2023-06-13 11:25:13,277   TMP=/tmp/.private/alexander
DEBUG 2023-06-13 11:25:13,277   JOURNAL_STREAM=8:29892
DEBUG 2023-06-13 11:25:13,277   XDG_SESSION_TYPE=wayland
DEBUG 2023-06-13 11:25:13,277   BASH_ENV=/home/alexander/.bashrc
DEBUG 2023-06-13 11:25:13,277   XDG_DATA_DIRS=/home/alexander/.local/share/flatpak/exports/share:/var/lib/flatpak/exports/share:/usr/local/share/:/usr/share/
DEBUG 2023-06-13 11:25:13,277   XDG_SESSION_DESKTOP=gnome
DEBUG 2023-06-13 11:25:13,277   TMPDIR=/tmp/.private/alexander
DEBUG 2023-06-13 11:25:13,277   GJS_DEBUG_OUTPUT=stderr
DEBUG 2023-06-13 11:25:13,277   SYSTEMD_PAGER=/usr/bin/less -FR
DEBUG 2023-06-13 11:25:13,277   MAIL=/var/mail/alexander
DEBUG 2023-06-13 11:25:13,277   SANDBOX_TMPDIR=/tmp/.private/alexander
DEBUG 2023-06-13 11:25:13,277   LESSKEY=/etc/.less
DEBUG 2023-06-13 11:25:13,277   SHELL=/bin/bash
DEBUG 2023-06-13 11:25:13,277   XDG_SESSION_CLASS=user
DEBUG 2023-06-13 11:25:13,277   GNOME_SETUP_DISPLAY=:1
DEBUG 2023-06-13 11:25:13,277   QT_IM_MODULE=ibus
DEBUG 2023-06-13 11:25:13,277   XMODIFIERS=@im=ibus
DEBUG 2023-06-13 11:25:13,277   CHROME_WRAPPER=true
DEBUG 2023-06-13 11:25:13,277   XDG_CURRENT_DESKTOP=GNOME
DEBUG 2023-06-13 11:25:13,277   GIO_LAUNCHED_DESKTOP_FILE=/usr/share/applications/UDSClient.desktop
DEBUG 2023-06-13 11:25:13,277   SHLVL=2
DEBUG 2023-06-13 11:25:13,277   G_FILENAME_ENCODING=utf8
DEBUG 2023-06-13 11:25:13,277   CHROME_VERSION_EXTRA=ALT Linux
DEBUG 2023-06-13 11:25:13,277   SANDBOX_LD_LIBRARY_PATH=/usr/lib64/chromium
DEBUG 2023-06-13 11:25:13,277   GDK_BACKEND=wayland
DEBUG 2023-06-13 11:25:13,277   GDMSESSION=gnome
DEBUG 2023-06-13 11:25:13,277   LOGNAME=alexander
DEBUG 2023-06-13 11:25:13,277   DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/500/bus
DEBUG 2023-06-13 11:25:13,277   XDG_RUNTIME_DIR=/run/user/500
DEBUG 2023-06-13 11:25:13,277   XAUTHORITY=/run/user/500/.mutter-Xwaylandauth.GKDK61
DEBUG 2023-06-13 11:25:13,277   PATH=/usr/lib64/chromium:/home/alexander/bin:/bin:/usr/bin:/usr/local/bin:/usr/games
DEBUG 2023-06-13 11:25:13,277   SBX_CHROME_API_RQ=1
DEBUG 2023-06-13 11:25:13,277   G_BROKEN_FILENAMES=1
DEBUG 2023-06-13 11:25:13,277   HISTSIZE=999
DEBUG 2023-06-13 11:25:13,277   GJS_DEBUG_TOPICS=JS ERROR;JS LOG
DEBUG 2023-06-13 11:25:13,277   HISTFILESIZE=9999
DEBUG 2023-06-13 11:25:13,277   SESSION_MANAGER=local/alexander:@/tmp/.ICE-unix/4599,unix/alexander:/tmp/.ICE-unix/4599
DEBUG 2023-06-13 11:25:13,277   LESSOPEN=|/usr/share/less/lesspipe.sh %s
DEBUG 2023-06-13 11:25:13,278   _=/usr/bin/gio
DEBUG 2023-06-13 11:25:13,278 Python path: ['/usr/lib/UDSClient', '/usr/lib64/python310.zip', '/usr/lib64/python3.10', '/usr/lib64/python3.10/lib-dynload', '/usr/lib64/python3/site-packages', '/usr/lib64/python3/site-packages/gtk-2.0', '/usr/lib/python3/site-packages']
DEBUG 2023-06-13 11:25:13,278 Python executable: /usr/bin/python3
DEBUG 2023-06-13 11:25:13,278 Python version: 3.10.8 (main, Dec 17 2022, 11:34:59) [GCC 12.1.1 20220518 (ALT Sisyphus 12.1.1-alt2)]
DEBUG 2023-06-13 11:25:13,278 Python version info: sys.version_info(major=3, minor=10, micro=8, releaselevel='final', serial=0)
DEBUG 2023-06-13 11:25:13,278 Python prefix: /usr
DEBUG 2023-06-13 11:25:13,278 Python base prefix: /usr
DEBUG 2023-06-13 11:25:13,278 Python executable: /usr/bin/python3
DEBUG 2023-06-13 11:25:13,278 Python argv: ['/usr/lib/UDSClient/UDSClient.py', 'udss://server_ip/k9tlnhwmcjxc1z0hfyolscdbmvk9hps71l6dys3y/1cLYJpzQ2m5odw8b4bKCQBbTIvpRCVxU', '-platform', 'xcb']
DEBUG 2023-06-13 11:25:13,278 Python modules path: ['/usr/lib/UDSClient', '/usr/lib64/python310.zip', '/usr/lib64/python3.10', '/usr/lib64/python3.10/lib-dynload', '/usr/lib64/python3/site-packages', '/usr/lib64/python3/site-packages/gtk-2.0', '/usr/lib/python3/site-packages']
DEBUG 2023-06-13 11:25:13,278 Python modules path (site): {'/usr/lib64/python310.zip': None, '/usr/lib64/python3.10': FileFinder('/usr/lib64/python3.10'), '/usr/lib64/python3.10/encodings': FileFinder('/usr/lib64/python3.10/encodings'), '/usr/lib64/python3.10/lib-dynload': FileFinder('/usr/lib64/python3.10/lib-dynload'), '/usr/lib64/python3/site-packages': FileFinder('/usr/lib64/python3/site-packages'), '/usr/lib64/python3.10/importlib': FileFinder('/usr/lib64/python3.10/importlib'), '/usr/lib/python3/site-packages': FileFinder('/usr/lib/python3/site-packages'), '/usr/lib64/python3/site-packages/gtk-2.0': FileFinder('/usr/lib64/python3/site-packages/gtk-2.0'), '/usr/lib/UDSClient/UDSClient.py': None, '/usr/lib/UDSClient': FileFinder('/usr/lib/UDSClient'), '/usr/lib64/python3.10/collections': FileFinder('/usr/lib64/python3.10/collections'), '/usr/lib64/python3/site-packages/PyQt5': FileFinder('/usr/lib64/python3/site-packages/PyQt5'), '/usr/lib/UDSClient/uds': FileFinder('/usr/lib/UDSClient/uds'), '/usr/lib64/python3.10/json': FileFinder('/usr/lib64/python3.10/json'), '/usr/lib64/python3.10/urllib': FileFinder('/usr/lib64/python3.10/urllib'), '/usr/lib64/python3.10/http': FileFinder('/usr/lib64/python3.10/http'), '/usr/lib64/python3.10/email': FileFinder('/usr/lib64/python3.10/email'), '/usr/lib64/python3/site-packages/cryptography': FileFinder('/usr/lib64/python3/site-packages/cryptography'), '/usr/lib64/python3/site-packages/cryptography/x509': FileFinder('/usr/lib64/python3/site-packages/cryptography/x509'), '/usr/lib64/python3/site-packages/cryptography/hazmat': FileFinder('/usr/lib64/python3/site-packages/cryptography/hazmat'), '/usr/lib64/python3/site-packages/cryptography/hazmat/bindings': FileFinder('/usr/lib64/python3/site-packages/cryptography/hazmat/bindings'), '/usr/lib64/python3/site-packages/cryptography/hazmat/primitives': FileFinder('/usr/lib64/python3/site-packages/cryptography/hazmat/primitives'), '/usr/lib64/python3/site-packages/cryptography/hazmat/primitives/serialization': FileFinder('/usr/lib64/python3/site-packages/cryptography/hazmat/primitives/serialization'), '/usr/lib64/python3/site-packages/cryptography/hazmat/primitives/asymmetric': FileFinder('/usr/lib64/python3/site-packages/cryptography/hazmat/primitives/asymmetric'), '/usr/lib64/python3/site-packages/cryptography/hazmat/primitives/ciphers': FileFinder('/usr/lib64/python3/site-packages/cryptography/hazmat/primitives/ciphers'), '/usr/lib64/python3/site-packages/bcrypt': FileFinder('/usr/lib64/python3/site-packages/bcrypt'), '/usr/lib/python3/site-packages/certifi': FileFinder('/usr/lib/python3/site-packages/certifi')}
DEBUG 2023-06-13 11:25:13,278 Python modules path (site): [<class 'zipimport.zipimporter'>, <function FileFinder.path_hook.<locals>.path_hook_for_FileFinder at 0x7fc2dd1bb9a0>]
DEBUG 2023-06-13 11:25:13,344 Initializing connector for linux(x86_64)
DEBUG 2023-06-13 11:25:13,344 Arguments: ['/usr/lib/UDSClient/UDSClient.py', 'udss://server_ip/k9tlnhwmcjxc1z0hfyolscdbmvk9hps71l6dys3y/1cLYJpzQ2m5odw8b4bKCQBbTIvpRCVxU']
DEBUG 2023-06-13 11:25:13,344 Mac OS *NOT* Detected
DEBUG 2023-06-13 11:25:13,344 URI: udss://server_ip/k9tlnhwmcjxc1z0hfyolscdbmvk9hps71l6dys3y/1cLYJpzQ2m5odw8b4bKCQBbTIvpRCVxU
DEBUG 2023-06-13 11:25:13,344 host:server_ip, ticket:k9tlnhwmcjxc1z0hfyolscdbmvk9hps71l6dys3y, scrambler:1cLYJpzQ2m5odw8b4bKCQBbTIvpRCVxU
DEBUG 2023-06-13 11:25:13,344 Setting request URL to https://server_ip/uds/rest/client
DEBUG 2023-06-13 11:25:13,344 Starting execution
INFO 2023-06-13 11:25:13,570 Hostname: alexander
DEBUG 2023-06-13 11:25:13,863 Transport data received
DEBUG 2023-06-13 11:25:13,865 Starting forwarder: ('0.0.0.0', 35389) -> ('tunnel_server_ip', 7777)
DEBUG 2023-06-13 11:25:13,865 Checking tunnel availability
INFO 2023-06-13 11:25:13,866 CONNECT to ('tunnel_server_ip', 7777)
WARNING 2023-06-13 11:25:13,878 Certificate checking is disabled!
DEBUG 2023-06-13 11:26:13,865 New connection limit reached
DEBUG 2023-06-13 11:26:13,866 Stopping servers
DEBUG 2023-06-13 11:26:13,940 Stoped forwarder ('0.0.0.0', 35389) -> ('tunnel_server_ip', 7777)
ERROR 2023-06-13 11:33:08,560 Error connecting to tunnel server ('0.0.0.0', 35389): [Errno 104] Соединение разорвано другой стороной
ERROR 2023-06-13 11:33:08,562 Error getting transport data
Traceback (most recent call last):
  File "/usr/lib/UDSClient/UDSClient.py", line 173, in getTransportData
    exec(
  File "<string>", line 50, in <module>
Exception: <p>Could not connect to tunnel server.</p><p>Please, check your network settings.</p>
ERROR 2023-06-13 11:33:08,563 got error: <p>Could not connect to tunnel server.</p><p>Please, check your network settings.</p>
DEBUG 2023-06-13 11:33:10,478 Execution finished correctly
DEBUG 2023-06-13 11:33:10,478 Exiting

At this time on the tunnel:

ERROR 2023-06-13 11:25:13,886 <socket.socket fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=0, laddr=('tunnel_server_ip', 7777), raddr=('my_ip', 40312)>, ('my_ip', 40312), ['__class__', '__del__', '__delattr__', '__dict__', '__dir__', '__doc__', '__enter__', '__eq__', '__exit__', '__format__', '__ge__', '__getattribute__', '__gt__', '__hash__', '__init__', '__init_subclass__', '__le__', '__lt__', '__module__', '__ne__', '__new__', '__reduce__', '__reduce_ex__', '__repr__', '__setattr__', '__sizeof__', '__str__', '__subclasshook__', '__weakref__', '_bad_message_length', '_check_closed', '_check_readable', '_check_writable', '_close', '_handle', '_poll', '_read', '_readable', '_recv', '_recv_bytes', '_send', '_send_bytes', '_writable', '_write', 'close', 'closed', 'fileno', 'poll', 'readable', 'recv', 'recv_bytes', 'recv_bytes_into', 'send', 'send_bytes', 'writable']
ERROR 2023-06-13 11:25:13,887 True True 6
ERROR 2023-06-13 11:25:13,894 HANDSHAKE invalid from my_ip: [Errno 32] Broken pipe

To the udstunnel.py file I have included the following lines:

logger.error(f'{client}, {addr}, {[i for i in dir(best_child)]}')
logger.error(f'{best_child._writable} {best_child._readable} {best_child._handle}')

Before the line:
executor.submit(process_connection, client, addr, best_child)
My service file matches yours.
I am using the 3.6 branch, async io is also present with me.
ps -aux showed the following results:

USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
openuds    21331  0.0  0.8  38036 32152 ?        Ss   11:33   0:00 UDSTunnel 0.0.0.0:7777
openuds    21335  0.0  0.6 259232 26828 ?        Sl   11:33   0:00 UDSTunnel 0.0.0.0:7777
openuds    21341  0.0  0.0      0     0 ?        Z    11:33   0:00 [UDSTunnel 0.0.0] <defunct>
openuds    21342  0.0  0.0      0     0 ?        Z    11:33   0:00 [UDSTunnel 0.0.0] <defunct>
root       21452  0.0  0.0   6564  2096 pts/0    S+   12:38   0:00 grep --color=auto -i tunnel

You can see in the client log that the client is waiting for a response from the tunnel server, but nothing happens for a while, after which I restart the tunnel service.
I did not specify the minimum TLS version (default is 1.2), but now I have specified it explicitly.

[dkmstr]

It's very strange indeed.. Can you provide more info?
Currently, it's running fine (i have it on production on several sites, and at least now it works correctly).
Can you test with current 3.6 branch?. Note that, in order to protect tunnel, the timeout for handshake is very low (as low as 3 seconds),

Sorry for not responding before, didn't notice your issue. :(

BTW. Master version is fully compatible with 3.6 version, at least at tunnel server, and has a lot of tests.. Maybe running them in your environment could give some more info?

Can you include, in the source code our your tunnel installation, a "logger.exception" clause on the point that is reporting the error?

Regards,

[dkmstr]

Looking at the code it's again very weird.. The code is very simple, on udstunnel.py:

• Waits for a connection (line 306)
• Submit the connection to a thread executor, to check the handshake (a simple constant string) (line 315)
• Tries to read HANDSHAKE length bytes (line 232)
  In your case, it fails, but no reason for that, except that the client is doing something weird.
  In the process of making stable the 3.6 (it's stable right now), several changes took place on client, maybe is something related to that?

[Future998]

I started to consistently upgrade my infrastructure to version 3.6. And found the following: the server version 3.6 works with the tunnel server version 3.5, however, when upgrading the tunnel server to version 3.6, the connection through the tunnel via xrdp stops working.

1. The client logs the following:

INFO 2023-05-24 16:40:25,913 Hostname: alexander
INFO 2023-05-24 16:40:26,165 CONNECT to ('tunnel server ip', 7777)
WARNING 2023-05-24 16:40:26,183 Certificate checking is disabled!

2. On the tunnel at this time:
   udp-tunnel UDSTunnel[7750]: ERROR - HANDSHAKE invalid from "my ip": [Error 32] Broken pipe
3. I reboot all tunnel services.
4. After that, the client issues an error in the GUI, and in the meantime the error is logged:

ERROR 2023-05-24 16:40:26,201 Error connecting to tunnel server ('0.0.0.0', 52679): [Errno 104] The connection is broken by the other side
ERROR 2023-05-24 16:40:26,202 got error: <p>Could not connect to tunnel server.</p><p>Please, check your network settings.</p>

Later, I found out exactly which line causes the error, I talked about it earlier. As I found out, it occurs in the process_connection function when conn.send((client, addr)) a call.

[dkmstr]

I think the problem is from the client or the script part.
Have you tried the latest client from 3.6?

Can you try one of the portables from here if you want...
https://images.udsenterprise.com/files/UDSClient/UDS-3.6.0/Portable/

can you take a dump of the connection with something like this?
tcpdump dst host YOUR_HOST_IP and port 443 -vvvnX 2>&1 > /tmp/out.txt

In the first few lines something like this will appear:

14:14:46.039087 IP (tos 0x0, ttl 113, id 44138, offset 0, flags [DF], proto TCP (6), length 47)
X.X.X.X.51511 > 192.168.0.7.443: Flags [P.], cksum 0x608e (correct), seq 0:7, ack 1, win 1026, length 7
0x0000: 4500 002f ac6a 4000 7106 3bae 4f74 118d E../[email protected].;.Ot..
0x0010: c0a8 0007 c937 01bb 85c9 156c 89c5 f305 .....7.....l....
0x0020: 5018 0402 608e 0000 5a4d 4742 a501 00 P...`...ZMGB...

Look at the ending 7 bytes, those are the handshake, "ZMGB\xA5\x01\x00" as you can see here.

openuds/tunnel-server/src/uds_tunnel/consts.py

Line 46 in 09c33ba

HANDSHAKE_V1: typing.Final[bytes] = b'\x5AMGB\xA5\x01\x00'

In my case, with a new connection, the third packet reveived was this (the first with data)

Let's see if we can solve this mystery :)

[Future998]

I have followed your instructions. Here's what I got:

14:00:36.286305 IP (tos 0x0, ttl 63, id 1554, offset 0, flags [DF], proto TCP (6), length 52)
    X.X.X.X.57350 > tunnel_ip.7777: Flags [S], cksum 0xc7dd (correct), seq 3117504787, win 64240, options [mss 1460,nop,nop,sackOK,nop,wscale 7], length 0
        0x0000:  4500 0034 0612 4000 3f06 9abc 0a04 819b  E..4..@.?.......
        0x0010:  0a04 0553 e006 1e61 b9d1 5913 0000 0000  ...S...a..Y.....
        0x0020:  8002 faf0 c7dd 0000 0204 05b4 0101 0402  ................
        0x0030:  0103 0307                                ....
14:00:36.286698 IP (tos 0x0, ttl 63, id 1555, offset 0, flags [DF], proto TCP (6), length 40)
    X.X.X.X.57350 > tunnel_ip.7777: Flags [.], cksum 0xcbad (correct), seq 3117504788, ack 3673905905, win 502, length 0
        0x0000:  4500 0028 0613 4000 3f06 9ac7 0a04 819b  E..(..@.?.......
        0x0010:  0a04 0553 e006 1e61 b9d1 5914 dafb 5af1  ...S...a..Y...Z.
        0x0020:  5010 01f6 cbad 0000 0000 0000 0000       P.............
14:00:36.291377 IP (tos 0x0, ttl 63, id 1556, offset 0, flags [DF], proto TCP (6), length 47)
    X.X.X.X.57350 > tunnel_ip.7777: Flags [P.], cksum 0x850d (correct), seq 0:7, ack 1, win 502, length 7
        0x0000:  4500 002f 0614 4000 3f06 9abf 0a04 819b  E../..@.?.......
        0x0010:  0a04 0553 e006 1e61 b9d1 5914 dafb 5af1  ...S...a..Y...Z.
        0x0020:  5018 01f6 850d 0000 5a4d 4742 a501 00    P.......ZMGB...
14:00:36.303666 IP (tos 0x0, ttl 63, id 1557, offset 0, flags [DF], proto TCP (6), length 255)
    X.X.X.X.57350 > tunnel_ip.7777: Flags [P.], cksum 0xeadb (correct), seq 7:222, ack 1, win 502, length 215
        0x0000:  4500 00ff 0615 4000 3f06 99ee 0a04 819b  E.....@.?.......
        0x0010:  0a04 0553 e006 1e61 b9d1 591b dafb 5af1  ...S...a..Y...Z.
        0x0020:  5018 01f6 eadb 0000 1603 0100 d201 0000  P...............
        0x0030:  ce03 034a 00e2 2717 44ab 82ab bab8 4e74  ...J..'.D.....Nt
        0x0040:  f228 5971 96c2 ffbf 7e7a 24d5 4fdb 7be4  .(Yq....~z$.O.{.
        0x0050:  c0ab b320 0cf3 c63d edf9 d88d 3bc3 21b9  .......=....;.!.
        0x0060:  56a0 b4cd b5ca 0a04 9249 84a3 8070 5e1a  V........I...p^.
        0x0070:  1319 a4f6 0008 1302 1303 1301 00ff 0100  ................
        0x0080:  007d 000b 0004 0300 0102 000a 000c 000a  .}..............
        0x0090:  001d 0017 001e 0019 0018 0023 0000 0016  ...........#....
        0x00a0:  0000 0017 0000 000d 001e 001c 0403 0503  ................
        0x00b0:  0603 0807 0808 0809 080a 080b 0804 0805  ................
        0x00c0:  0806 0401 0501 0601 002b 0003 0203 0400  .........+......
        0x00d0:  2d00 0201 0100 3300 2600 2400 1d00 209e  -.....3.&.$.....
        0x00e0:  3055 aa18 8f2f e1cc c493 b213 d977 67ba  0U.../.......wg.
        0x00f0:  8d4c c369 eb24 ae41 6830 f5c4 b1e4 6b    .L.i.$.Ah0....k

Meanwhile, in the file consts.py:
HANDSHAKE_V1: typing.Final[bytes] = b'\x5AMGB\xA5\x01\x00'
I tried the client version 3.6.

[dkmstr]

There is no mor communications after last packet?
The Handshake is there, it's sent and it's fine (ZMGB...)...

I have tested again, even on an arm64 machine (the tunnel), and works fine... :(

Try, on your client, create a "uds-debug-on" file on your home folder (will trigger debugging on client), and also set the configuration on the tunnel to debug (/etc/udstunnel.cfg).Also, if you can do it, modify and try to put some logs on the failing line in question on the source code of the tunnel to see if we can detect what happens...

BTW, this is my tunnel.service file content (i don't believe the problem comes from here, but for reference...):
---- CUT HERE ---
[Unit]
Description=UDS Tunnel server
After=network.target

[Service]
User=root
Group=tomcat
RuntimeDirectory=uds
SyslogIdentifier=UDSTunnel
LimitNOFILE=4096
ExecStart=/usr/bin/python3 /usr/share/uds/tunnel/udstunnel.py -t
PrivateTmp=true
Restart=always
RestartSec=16

[Install]
WantedBy=multi-user.target
---- CUT HERE ----
Let's see id the problem comes in the incomming connection, or sending the socket to a worker (in that case, maybe something about security because of the comm socket being used??)

Which commit version is working for you on 3.5? the 3.5 version was based on curio, and 3.6 version is based on asyncio (standard lib, curio says it is not to be maintained anymore)

Also, how many processes of udstunnel are running? Can you provide a sample of "ps -aux" output for tunnel processes with full command (only uds tunnel processed are significant...)

Also, let me know if there is some response from UDS tunnel (to try to imagine WHERE is failing)..

tcpdump host YOUR_HOST_IP and port 443 -vvvnX 2>&1 > /tmp/out.txt (in your case, i thing the port is 7777)
(Note that the dst is removed).

Also, try to reduce SSL requirements to 1.2 on configuration file... i dont think that is the problem, but maybe (i.e. I have had problems with MacOS and tls1.3...).

[dkmstr]

Mmmm.. those two "defunct" processes don't likes me. The top two ones, are the "dispatchers", but processors are those defunct...

I'm going to install an alt linux myself on an VM, and let try it.. Because it's strange (something related to permissions, or missing packages?)

Meanwhile, can you also download the "master" tunnel from https://github.com/VirtualCable/uds-tunnel-server? (Now it's on an specific git, but it is present as a submodule on openuds, that you can download all and take same structure as 3.6 version with "git submodule update --init --recursive").

Install pytest, and try to run the tunnel tests (simply run in on main folder), to see if we can see something with this (Basically, 4.0 right now is 3.6 version + tests + some minor changes)...

Note: You will see "ERROR" on test logs, but that is fine, the important part is that all tests get "PASSED"
Something like this:
"2023-06-13 15:28:31" ERROR CONNECTION FAILED: [Errno 111] Connection refused"
""2023-06-13 15:28:31" ERROR CONNECTION FAILED: [Errno 111] Connection refused"
PASSED [ 87%]
tests/test_udstunnel.py::TestUDSTunnelMainProc::test_tunnel_open PASSED [ 93%]
tests/test_udstunnel.py::TestUDSTunnelMainProc::test_tunnel_test PASSED [100%]

============================================================================= 16 passed in 54.00s ==============================================================================

The important part is 16 passed.

[Future998]

Here's what the systemctl status openuds-tunnel.service shows:

● openuds-tunnel.service - OpenUDS Tunnel server
     Loaded: loaded (/lib/systemd/system/openuds-tunnel.service; enabled; preset: disabled)
     Active: active (running) since Tue 2023-06-13 13:12:19 MSK; 4h 30min ago
   Main PID: 2638 (UDSTunnel 0.0.0)
      Tasks: 8 (limit: 4677)
     Memory: 50.7M
        CPU: 4.374s
     CGroup: /system.slice/openuds-tunnel.service
             ├─2638 "UDSTunnel 0.0.0.0:7777"
             └─3851 "UDSTunnel 0.0.0.0:7777"

июн 13 13:12:19 ouds-tunnel systemd[1]: Started openuds-tunnel.service - OpenUDS Tunnel server.

In the configuration file:
workers = 2
By the way, in this case, I used alt-server-10.0.
After running the tests, I saw the following (I specify only those that failed):

================================================================================================================== FAILURES ==================================================================================================================
___________________________________________________________________________________________________ TestUDSTunnelApp.test_app_concurrency ____________________________________________________________________________________________________

self = <tests.test_concurrency.TestUDSTunnelApp testMethod=test_app_concurrency>

>   ???

/usr/share/openuds/tests/test_concurrency.py:148: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/lib64/python3.10/contextlib.py:199: in __aenter__
    return await anext(self.gen)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

host = '127.0.0.1', port = 20001, wait_for_port = True, args = None, kwargs = {'command_timeout': 16, 'logfile': '/tmp/tunnel_test.log', 'loglevel': 'DEBUG', 'uds_server': 'http://127.0.0.1:20000/uds/rest', ...}

    @contextlib.asynccontextmanager
    async def tunnel_app_runner(
        host: typing.Optional[str] = None,
        port: typing.Optional[int] = None,
        *,
        wait_for_port: bool = False,
        args: typing.Optional[typing.List[str]] = None,
        **kwargs: typing.Union[str, int, bool],
    ) -> collections.abc.AsyncGenerator['Process', None]:
        # Ensure we are on src directory
        if os.path.basename(os.getcwd()) != 'src':
>           os.chdir('src')
E           FileNotFoundError: [Errno 2] No such file or directory: 'src'

tests/utils/tuntools.py:432: FileNotFoundError
_______________________________________________________________________________________________ TestUDSTunnelApp.test_tunnel_proc_concurrency ________________________________________________________________________________________________

listen_host = '::1', listen_port = 20001, remote_host = '0.0.0.0', remote_port = 0, response = <function TestUDSTunnelApp.test_tunnel_proc_concurrency.<locals>.<lambda> at 0x7f4a3bf53130>, use_fake_http_server = False
global_stats = <uds_tunnel.stats.GlobalStats object at 0x7f4a3bf76b60>, kwargs = {'command_timeout': 16}, hhost = '[::1]', args = <MagicMock id='139956748584560'>
provider = <function create_tunnel_proc.<locals>.provider at 0x7f4a381a5e10>, cfgfile = '/tmp/.private/root/conf-loki9o23'

    @contextlib.asynccontextmanager
    async def create_tunnel_proc(
        listen_host: str,
        listen_port: int,
        remote_host: str = '0.0.0.0',  # nosec: intentionally value, Not used if response is provided
        remote_port: int = 0,  # Not used if response is provided
        *,
        response: typing.Optional[
            typing.Union[
                typing.Callable[[bytes], typing.Mapping[str, typing.Any]],
                typing.Mapping[str, typing.Any],
            ]
        ] = None,
        use_fake_http_server: bool = False,
        global_stats: typing.Optional[stats.GlobalStats] = None,
        # Configuration parameters
        **kwargs,
    ) -> collections.abc.AsyncGenerator[
        typing.Tuple['config.ConfigurationType', typing.Optional[asyncio.Queue[bytes]]],
        None,
    ]:
        """Creates a "tunnel proc" server, that is, a tunnel server that will be
           invoked by udstunnel subpoocesses.
    
        Args:
            listen_host (str): Host to listen on
            listen_port (int): Port to listen on
            remote_host (str): Remote host to connect to
            remote_port (int): Remote port to connect to
            response (typing.Optional[typing.Union[typing.Callable[[bytes], typing.Mapping[str, typing.Any]], typing.Mapping[str, typing.Any]]], optional): Response to send to the client. Defaults to None.
            use_fake_http_server (bool, optional): If True, a fake http server will be used instead of a mock. Defaults to False.
    
        Yields:
            collections.abc.AsyncGenerator[typing.Tuple[config.ConfigurationType, typing.Optional[asyncio.Queue[bytes]]], None]: A tuple with the configuration
                and a queue with the data received by the "fake_http_server" if used, or None if not used
        """
    
        # Ensure response
        if response is None:
            response = conf.UDS_GET_TICKET_RESPONSE(remote_host, remote_port)
    
        port = random.randint(20000, 40000)  # nosec  Just a random port
        hhost = f'[{listen_host}]' if ':' in listen_host else listen_host
        args = {
            'uds_server': f'http://{hhost}:{port}/uds/rest',
        }
        args.update(kwargs)  # Add extra args
        # If use http server instead of mock
        # We will setup a different context provider
        if use_fake_http_server:
            resp = conf.UDS_GET_TICKET_RESPONSE(remote_host, remote_port)
    
            @contextlib.asynccontextmanager
            async def provider() -> collections.abc.AsyncGenerator[typing.Optional[asyncio.Queue[bytes]], None]:
                async with create_fake_broker_server(listen_host, port, response=response or resp) as queue:
                    try:
                        yield queue
                    finally:
                        pass
    
        else:
    
            @contextlib.asynccontextmanager
            async def provider() -> collections.abc.AsyncGenerator[typing.Optional[asyncio.Queue[bytes]], None]:
                with mock.patch(
                    'uds_tunnel.tunnel.TunnelProtocol._read_from_uds',
                    new_callable=tools.AsyncMock,
                ) as m:
                    if callable(response):
                        m.side_effect = lambda cfg, ticket, *args, **kwargs: response(ticket)  # type: ignore
                    else:
                        m.return_value = response
                    try:
                        yield None
                    finally:
                        pass
    
        with create_config_file(listen_host, listen_port, **args) as cfgfile:
            args = mock.MagicMock()
            # Config can be a file-like or a path
            args.config = cfgfile
            args.ipv6 = False  # got from config file
    
            # Load config here also for testing
            cfg = config.read(cfgfile)
    
            async with provider() as possible_queue:
                # Stats collector
                global_stats = global_stats or stats.GlobalStats()  # If none provided, create a new one
                # Pipe to send data to tunnel
                own_end, other_end = multiprocessing.Pipe()
    
                udstunnel.setup_log(cfg)
    
                # Clear the stop flag
                udstunnel.do_stop.clear()
    
                # Create the tunnel task
                task = asyncio.create_task(udstunnel.tunnel_proc_async(other_end, cfg, global_stats.ns))
    
                # Server listening for connections
                server_socket = socket.socket(
                    socket.AF_INET6 if ':' in listen_host else socket.AF_INET, socket.SOCK_STREAM
                )
                server_socket.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)  # Allow reuse of address
                server_socket.bind((listen_host, listen_port))
                server_socket.listen(8)
                server_socket.setblocking(False)
    
                async def server():
                    loop = asyncio.get_running_loop()
                    try:
                        while True:
                            client, addr = await loop.sock_accept(server_socket)
                            # Send the socket to the tunnel
                            own_end.send((client.dup(), addr))
                            client.close()
                    except asyncio.CancelledError:
                        pass  # We are closing
                    except Exception:
                        logger.exception('Exception in server')
                    # Close the socket
                    server_socket.close()
    
                # Create the middleware task
                server_task = asyncio.create_task(server())
                try:
>                   yield cfg, possible_queue

tests/utils/tuntools.py:235: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <tests.test_concurrency.TestUDSTunnelApp testMethod=test_tunnel_proc_concurrency>

>   ???

/usr/share/openuds/tests/test_concurrency.py:215: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <tests.test_concurrency.TestUDSTunnelApp testMethod=test_tunnel_proc_concurrency>, first = 878, second = 1024, msg = None

    def assertEqual(self, first, second, msg=None):
        """Fail if the two objects are unequal as determined by the '=='
           operator.
        """
        assertion_func = self._getAssertEqualityFunc(first, second)
>       assertion_func(first, second, msg=msg)

/usr/lib64/python3.10/unittest/case.py:845: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <tests.test_concurrency.TestUDSTunnelApp testMethod=test_tunnel_proc_concurrency>, first = 878, second = 1024, msg = '878 != 1024'

    def _baseAssertEqual(self, first, second, msg=None):
        """The default assertEqual implementation, not type specific."""
        if not first == second:
            standardMsg = '%s != %s' % _common_shorten_repr(first, second)
            msg = self._formatMessage(msg, standardMsg)
>           raise self.failureException(msg)
E           AssertionError: 878 != 1024

/usr/lib64/python3.10/unittest/case.py:838: AssertionError

During handling of the above exception, another exception occurred:

self = <tests.test_concurrency.TestUDSTunnelApp testMethod=test_tunnel_proc_concurrency>

>   ???

/usr/share/openuds/tests/test_concurrency.py:195: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/lib64/python3.10/contextlib.py:217: in __aexit__
    await self.gen.athrow(typ, value, traceback)
tests/utils/tuntools.py:246: in create_tunnel_proc
    await task
udstunnel.py:223: in tunnel_proc_async
    await asyncio.wait(tasks, return_when=asyncio.ALL_COMPLETED)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

fs = []

    async def wait(fs, *, timeout=None, return_when=ALL_COMPLETED):
        """Wait for the Futures and coroutines given by fs to complete.
    
        The fs iterable must not be empty.
    
        Coroutines will be wrapped in Tasks.
    
        Returns two sets of Future: (done, pending).
    
        Usage:
    
            done, pending = await asyncio.wait(fs)
    
        Note: This does not raise TimeoutError! Futures that aren't done
        when the timeout occurs are returned in the second set.
        """
        if futures.isfuture(fs) or coroutines.iscoroutine(fs):
            raise TypeError(f"expect a list of futures, not {type(fs).__name__}")
        if not fs:
>           raise ValueError('Set of coroutines/Futures is empty.')
E           ValueError: Set of coroutines/Futures is empty.

/usr/lib64/python3.10/asyncio/tasks.py:368: ValueError

------------------------------------------------------------------------------------------------------------- Captured log call --------------------------------------------------------------------------------------------------------------
ERROR    udstunnel:udstunnel.py:134 Receiving data from parent process
Traceback (most recent call last):
  File "/usr/share/openuds/tunnel/udstunnel.py", line 126, in get_socket
    msg: typing.Optional[typing.Tuple[socket.socket, typing.Tuple[str, int]]] = pipe.recv()
  File "/usr/lib64/python3.10/multiprocessing/connection.py", line 256, in recv
    return _ForkingPickler.loads(buf.getbuffer())
  File "/usr/lib64/python3.10/multiprocessing/reduction.py", line 246, in _rebuild_socket
    fd = df.detach()
  File "/usr/lib64/python3.10/multiprocessing/resource_sharer.py", line 58, in detach
    return reduction.recv_handle(conn)
  File "/usr/lib64/python3.10/multiprocessing/reduction.py", line 189, in recv_handle
    return recvfds(s, 1)[0]
  File "/usr/lib64/python3.10/multiprocessing/reduction.py", line 164, in recvfds
    raise RuntimeError('received %d items of ancdata' %
RuntimeError: received 0 items of ancdata
ERROR    tests.utils.tuntools:tuntools.py:228 Exception in server
Traceback (most recent call last):
  File "/usr/share/openuds/tunnel/tests/utils/tuntools.py", line 223, in server
    own_end.send((client.dup(), addr))
  File "/usr/lib64/python3.10/multiprocessing/connection.py", line 211, in send
    self._send_bytes(_ForkingPickler.dumps(obj))
  File "/usr/lib64/python3.10/multiprocessing/connection.py", line 416, in _send_bytes
    self._send(header + buf)
  File "/usr/lib64/python3.10/multiprocessing/connection.py", line 373, in _send
    n = write(self._handle, buf)
BrokenPipeError: [Errno 32] Broken pipe

___________________________________________________________________________________________________ TestUDSTunnelApp.test_app_concurrency ____________________________________________________________________________________________________

self = <tests.test_concurrency.TestUDSTunnelApp testMethod=test_app_concurrency>

>   ???

/usr/share/openuds/tests/test_concurrency.py:148: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/lib64/python3.10/contextlib.py:199: in __aenter__
    return await anext(self.gen)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

host = '127.0.0.1', port = 20001, wait_for_port = True, args = None, kwargs = {'command_timeout': 16, 'logfile': '/tmp/tunnel_test.log', 'loglevel': 'DEBUG', 'uds_server': 'http://127.0.0.1:20000/uds/rest', ...}

    @contextlib.asynccontextmanager
    async def tunnel_app_runner(
        host: typing.Optional[str] = None,
        port: typing.Optional[int] = None,
        *,
        wait_for_port: bool = False,
        args: typing.Optional[typing.List[str]] = None,
        **kwargs: typing.Union[str, int, bool],
    ) -> collections.abc.AsyncGenerator['Process', None]:
        # Ensure we are on src directory
        if os.path.basename(os.getcwd()) != 'src':
>           os.chdir('src')
E           FileNotFoundError: [Errno 2] No such file or directory: 'src'

tests/utils/tuntools.py:432: FileNotFoundError

========================================================================================================== short test summary info ===========================================================================================================
FAILED tests/test_concurrency.py::TestUDSTunnelApp::test_app_concurrency - FileNotFoundError: [Errno 2] No such file or directory: 'src'
FAILED tests/test_concurrency.py::TestUDSTunnelApp::test_tunnel_proc_concurrency - ValueError: Set of coroutines/Futures is empty.
FAILED tests/test_udstunnel.py::TestUDSTunnelMainProc::test_run_app_help - FileNotFoundError: [Errno 2] No such file or directory: 'src'

[dkmstr]

Stupid of me...
I found the error, the runner process was not running the process if uvloop variable was set but no uvloop was found (that is the default config bundled as example)...

Now it seems to works fine.

I update the master and 3.6 versions with the fix...

Sorry for the inconveniences, and thank you a lot for your help!!.

Note: It worked for me because i don't had the use_uvloop set to True when did my tests, and this simple get unnoticed... :(

Please, upgrade your installation and let me know if it works fine now :)

This is the fix provided: 20e4461

[dkmstr]

Anyway, if you can, include uvloop as dependency, is really faster processing event loops that asyncio is, and we can always remove it in a future if not maintained anymore :)

[Future998]

I am extremely grateful to you for your help, everything has worked.

[dkmstr]

Thanks to you for helping in locating the bug :)

Regards,