Odd issue with FTPS over OpenZiti Overlay

Hello,

I'm setting up a cloud hosted webserver using HestiaCP, and it's using ProFTPD as the FTP server. I have the linux tunneler installed and working on that server, and ZDEW on my Windows 10 Machine, and they connect to the single router/controller I have hosted at the same site as my ZDEW. I have allowed port 21 and the passive ports (12000-12100) in Ziti intercept and enabled "forward port" on the host config. with the allowed port ranges there as well.

Using FTPS (Explicit over port 21) on the public IP (no Ziti) I can successfully authenticate and list directories and transfer files (passive mode), but when using OpenZiti which connects to 127.0.0.1 on the linux tunneller app, the connection succeeds but the passive mode sometimes fails (it's intermittant), as per FileZilla logs below. I notice the directory listing is also noticeably slower when using the overlay network.

Status: Server sent passive reply with unroutable address. Using server address instead.
Command: MLSD
Error: GnuTLS error -15: An unexpected TLS packet was received.
Error: The data connection could not be established: ECONNABORTED - Connection aborted

I've been trying to use AI/Googling to resolve this but nothing seems to be working.

The ZDEW logs show the following:

[2025-04-10T20:44:00.419Z] INFO tunnel-cbs:ziti_dns.c:566 format_resp() found record[100.64.0.15] for query[1:cp.cloud.joshh.net]
[2025-04-10T20:44:02.166Z] ERROR tunnel-sdk:tunnel_tcp.c:190 on_tcp_client_err() client=tcp:100.64.0.1:34149 err=-14, terminating connection
[2025-04-10T20:44:03.687Z] ERROR tunnel-sdk:tunnel_tcp.c:190 on_tcp_client_err() client=tcp:100.64.0.1:34152 err=-14, terminating connection
[2025-04-10T20:44:06.548Z] ERROR tunnel-sdk:tunnel_tcp.c:190 on_tcp_client_err() client=tcp:100.64.0.1:34154 err=-14, terminating connection
[2025-04-10T20:44:06.567Z] WARN ziti-sdk:channel.c:553 dispatch_message() ch[0] received message without conn_id or for unknown connection ct[ED72] conn_id[11]
[2025-04-10T20:44:12.094Z] ERROR tunnel-sdk:tunnel_tcp.c:190 on_tcp_client_err() client=tcp:100.64.0.1:34160 err=-14, terminating connection

ProFTPD TLS logs:

2025-04-10 20:44:00,793 mod_tls/2.9.2[324797]: TLS/TLS-C requested, starting TLS handshake │
2025-04-10 20:44:00,874 mod_tls/2.9.2[324797]: TLSv1.3 connection accepted, using cipher TLS_AES_128_GCM_SHA256 (12│
8 bits) │
2025-04-10 20:44:01,237 mod_tls/2.9.2[324797]: Protection set to Private │
2025-04-10 20:44:02,396 mod_tls/2.9.2[324797]: SSL_shutdown error: SSL: │
(1) error:0A000126:SSL routines::unexpected eof while reading │
(2) error:0A000197:SSL routines::shutdown while in init │
2025-04-10 20:44:02,843 mod_tls/2.9.2[324822]: TLS/TLS-C requested, starting TLS handshake │
2025-04-10 20:44:02,950 mod_tls/2.9.2[324822]: TLSv1.3 connection accepted, using cipher TLS_AES_128_GCM_SHA256 (12│
8 bits) │
2025-04-10 20:44:03,297 mod_tls/2.9.2[324822]: Protection set to Private │
2025-04-10 20:44:03,917 mod_tls/2.9.2[324822]: SSL_shutdown error: SSL: │
(1) error:0A000126:SSL routines::unexpected eof while reading │
(2) error:0A000197:SSL routines::shutdown while in init │
2025-04-10 20:44:04,460 mod_tls/2.9.2[324823]: TLS/TLS-C requested, starting TLS handshake │
2025-04-10 20:44:04,573 mod_tls/2.9.2[324823]: TLSv1.3 connection accepted, using cipher TLS_AES_128_GCM_SHA256 (12│
8 bits) │
2025-04-10 20:44:04,946 mod_tls/2.9.2[324823]: Protection set to Private │
2025-04-10 20:44:32,631 mod_tls/2.9.2[324848]: TLS/TLS-C requested, starting TLS handshake │
2025-04-10 20:44:32,741 mod_tls/2.9.2[324848]: TLSv1.3 connection accepted, using cipher TLS_AES_128_GCM_SHA256 (12│
8 bits) │
2025-04-10 20:44:33,040 mod_tls/2.9.2[324848]: Protection set to Private

Any ideas on what I could try or how to resolve this?

It's been quite a while since i tried FTP and I've never used FTPS. when i used ftp in pasv mode, the server would have an advertised address that's negotiated during the client connecting to the ftp server. This was generally an ip address that the client was supposed to use. If memory serves, that advertised ip had to be intercepted because that's how ftp works.

The best thing to do is to capture packets on both sides and then analyze those packets looking for timeouts or resets etc, indicating a problem, and something to look into.

I fear that's all I'll probably be able to offer right now. If anyone else has thoughts, hopefully they'll share. If anything else comes to mind I'll follow up.

From gpt

Client                                Server (FTP Passive Mode)
  |                                          |
  |------- TCP 21 (control connection) ----->|
  |<------ 227 Entering Passive Mode --------|
  |        (e.g., 192,168,1,10,195,80)       |
  |                                          |
  |------- TCP 50000 (data connection) ----->|  <- port 50000 = (195*256 + 80)
  |<-------- Data transfer or file ----------|
  |                                          |

Control conn: client → server on TCP 21

Server replies with IP:PORT for passive data conn

Client initiates separate TCP conn to that IP:PORT

Data flows over this new conn initiated by client

Hi @TheLumberjack,

Yes the FTP server does send a Passive IP to connect to (which is always wrong given how the Ziti tunnel works... I've tried putting an IP as an intercept and configur ProFTPD to send that IP and it does not seem to work correctly, either). But the good news is Filezilla is smart enough to attempt the data connection to the actual server IP rather than what it "reports" its IP to be, so we can ignore that for now. The control connection appears fine, this is specifically with the data connection.

I captured packets on my windows machine on the ziti tunnel and saw the connection error/RST ACK as per attached screenshot, and I noticed the ziti log aligns with the exact time of the FTPS reset - it appears it may be OpenZiti that is disconnecting if I read these logs right:

[2025-04-11T20:10:18.282Z] ERROR tunnel-sdk:tunnel_tcp.c:190 on_tcp_client_err() client=tcp:100.64.0.1:26186 err=-14, terminating connection
[2025-04-11T20:10:22.663Z] ERROR tunnel-sdk:tunnel_tcp.c:190 on_tcp_client_err() client=tcp:100.64.0.1:26190 err=-14, terminating connection

A rundown on the packet capture from Gemini AI:

  • Packet 148 (Client -> Server): TCP [SYN] - Client initiates connection to port 12001.
  • Packet 151 (Server -> Client): TCP [SYN, ACK] - Server acknowledges and sends its SYN.
  • Packet 152 (Client -> Server): TCP [ACK] - Client acknowledges. The TCP connection on port 12001 is successfully established. This confirms Ziti is correctly forwarding this passive port and ProFTPD (or the tunneler) initially accepted the connection. It rules out the idea that specific passive ports are simply blocked or not configured in Ziti.
  • Packet 153 (Client -> Server): TLSv1.2 Client Hello - The client starts the TLS handshake over the new data connection.
  • Packet 154 (Server -> Client): TCP [ACK] - The server acknowledges receiving the Client Hello packet.
  • Packet 155 (Server -> Client): TCP [RST, ACK] - This is the failure point. Immediately after acknowledging the Client Hello, the server side (100.64.0.15) sends a TCP Reset (RST) packet, abruptly killing the data connection.

I haven't captured from the server side yet, but now I'm suspecting it's the ziti tunnel going down/resetting. This does not seem to be a passive ip/port issue so much as the connection for data DOES happen, it's just immediately interrupted.

I tried to find relating Ziti Router logs as well... there are some errors reported here, but I'm not sure what they mean:

Apr 11 20:10:14 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:159","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Tx","level":"info","msg":"sending dial: seq: 902 , connId: 256, newConnId: 0, circuitId: 9PpZNxlGaB","time":"2025-04-11T20:10:14.925Z"}
Apr 11 20:10:14 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:147","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Rx","level":"info","msg":"received dial result: seq: 903 , replyTo: 902, connId: 256, newConnId: 439, success: true, msg: ","time":"2025-04-11T20:10:14.967Z"}
Apr 11 20:10:15 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:159","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Tx","level":"info","msg":"sending dial: seq: 919 , connId: 327, newConnId: 0, circuitId: ct6WN4kdP","time":"2025-04-11T20:10:15.880Z"}
Apr 11 20:10:15 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:147","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Rx","level":"info","msg":"received dial result: seq: 919 , replyTo: 919, connId: 327, newConnId: 440, success: true, msg: ","time":"2025-04-11T20:10:15.928Z"}
Apr 11 20:10:16 HOME2ZITI ziti[39384]: {"_context":"{c/ct6WN4kdP|@/ZXlr}\u003cInitiator\u003e","file":"github.com/openziti/ziti/router/xgress/xgress.go:571","func":"github.com/openziti/ziti/router/xgress.(*Xgress).flushSendThenClose.func1","level":"info","msg":"sending end of circuit payload","time":"2025-04-11T20:10:16.139Z"}
Apr 11 20:10:18 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:159","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Tx","level":"info","msg":"sending dial: seq: 928 , connId: 327, newConnId: 0, circuitId: lsGZExlda","time":"2025-04-11T20:10:18.641Z"}
Apr 11 20:10:18 HOME2ZITI ziti[39384]: {"_context":"{c/9PpZNxlGaB|@/jvLp}\u003cInitiator\u003e","file":"github.com/openziti/ziti/router/xgress/xgress.go:571","func":"github.com/openziti/ziti/router/xgress.(*Xgress).flushSendThenClose.func1","level":"info","msg":"sending end of circuit payload","time":"2025-04-11T20:10:18.642Z"}
Apr 11 20:10:18 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:147","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Rx","level":"info","msg":"received dial result: seq: 929 , replyTo: 928, connId: 327, newConnId: 441, success: true, msg: ","time":"2025-04-11T20:10:18.763Z"}
Apr 11 20:10:22 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:159","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Tx","level":"info","msg":"sending dial: seq: 948 , connId: 256, newConnId: 0, circuitId: zw.WExldP","time":"2025-04-11T20:10:22.830Z"}
Apr 11 20:10:22 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:147","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Rx","level":"info","msg":"received dial result: seq: 947 , replyTo: 948, connId: 256, newConnId: 442, success: true, msg: ","time":"2025-04-11T20:10:22.878Z"}
Apr 11 20:10:23 HOME2ZITI ziti[39384]: {"_context":"{c/zw.WExldP|@/6KDd}\u003cInitiator\u003e","file":"github.com/openziti/ziti/router/xgress/xgress.go:571","func":"github.com/openziti/ziti/router/xgress.(*Xgress).flushSendThenClose.func1","level":"info","msg":"sending end of circuit payload","time":"2025-04-11T20:10:23.023Z"}
Apr 11 20:10:42 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:159","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Tx","level":"info","msg":"sending dial: seq: 954 , connId: 256, newConnId: 0, circuitId: xGPRNxkdP","time":"2025-04-11T20:10:42.837Z"}
Apr 11 20:10:43 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:147","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Rx","level":"info","msg":"received dial result: seq: 950 , replyTo: 954, connId: 256, newConnId: 443, success: true, msg: ","time":"2025-04-11T20:10:43.134Z"}
Apr 11 20:10:44 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:159","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Tx","level":"info","msg":"sending dial: seq: 971 , connId: 266, newConnId: 0, circuitId: v-ORN4kda","time":"2025-04-11T20:10:44.010Z"}
Apr 11 20:10:44 HOME2ZITI ziti[39384]: {"file":"github.com/openziti/ziti/router/xgress_edge/accept.go:147","func":"github.com/openziti/ziti/router/xgress_edge.debugPeekHandler.Rx","level":"info","msg":"received dial result: seq: 966 , replyTo: 971, connId: 266, newConnId: 444, success: true, msg: ","time":"2025-04-11T20:10:44.056Z"}
Apr 11 20:10:44 HOME2ZITI ziti[39384]: {"_context":"{c/v-ORN4kda|@/bmeO}\u003cInitiator\u003e","file":"github.com/openziti/ziti/router/xgress/xgress.go:571","func":"github.com/openziti/ziti/router/xgress.(*Xgress).flushSendThenClose.func1","level":"info","msg":"sending end of circuit payload","time":"2025-04-11T20:10:44.362Z"}
Apr 11 20:10:44 HOME2ZITI ziti[39384]: {"_context":"{c/v-ORN4kda|@/zvxL}\u003cTerminator\u003e","file":"github.com/openziti/ziti/router/xgress/xgress.go:571","func":"github.com/openziti/ziti/router/xgress.(*Xgress).flushSendThenClose.func1","level":"info","msg":"sending end of circuit payload","time":"2025-04-11T20:10:44.363Z"}
Apr 11 20:10:44 HOME2ZITI ziti[39384]: {"_context":"{c/v-ORN4kda|@/zvxL}\u003cTerminator\u003e","circuitId":"v-ORN4kda","error":"cannot forward payload, no destination for circuit=v-ORN4kda src=zvxL dst=bmeO","file":"github.com/openziti/ziti/router/handler_xgress/receive.go:41","func":"github.com/openziti/ziti/router/handler_xgress.(*receiveHandler).HandleXgressReceive","level":"error","msg":"unable to forward payload","origin":1,"seq":5,"time":"2025-04-11T20:10:44.363Z"}
Apr 11 20:10:48 HOME2ZITI ziti[39384]: {"circuitCount":1,"ctrlId":"ctrl.ziti.domain.net","file":"github.com/openziti/ziti/router/forwarder/faulter.go:107","func":"github.com/openziti/ziti/router/forwarder.(*Faulter).run","level":"warning","msg":"reported forwarding faults","time":"2025-04-11T20:10:48.636Z"}

Edit: I should clarify this error does not happen every-time... it's seemingly random but happens often enough it's interupting the workflow.

In my experience, this has often been caused by the other side closing the connection immediately. For example, FTPS, is there some kind of certificate problem? It definitely would be a good idea to see if the traffic makes it to the other side via logs and/or tcpdump (wireshark) on the far side.